4
現在、log4j2を使用してログユーティリティから最高のパフォーマンスを引き出す方法を模索しています。 log4j.propertiesは非同期ロガーを使用すると、Log4J2で大量のログエントリを書き込むのが遅い
status = error
name = PropertiesConfig
property.log-path = /Users/petervannes/NetBeansProjects/JSONLogger_2/logfiles
appender.console.type = Console
appender.console.name = SYSTEM_OUT
appender.console.layout.type = PatternLayout
appender.console.layout.pattern = %m%n
appender.rolling.type = RollingFile
appender.rolling.name = RollingFile
appender.rolling.immediateFlush = true
appender.rolling.fileName = ${log-path}/jsonlogger.json
appender.rolling.filePattern = ${log-path}/%d{yyyyMMdd}_jsonlogger-%i.json
appender.rolling.layout.type = PatternLayout
appender.rolling.layout.pattern = %m%n
appender.rolling.policies.type = Policies
appender.rolling.policies.size.type = SizeBasedTriggeringPolicy
appender.rolling.policies.size.size= 1MB
appender.rolling.strategy.type = DefaultRolloverStrategy
appender.rolling.strategy.max = 4
logger.rolling.name = JSONLogger
logger.rolling.level = debug
logger.rolling.additivity = false
logger.rolling.appenderRef.rolling.ref = RollingFile
rootLogger.level = FATAL
rootLogger.appenderRef.stdout.ref = SYSTEM_OUT
です.100,000ログエントリを書き込むと、私のシステムは約4623msとなります。
クラスパスにlog4j2.component.propertiesを作成して、すべてのロガーを非同期にするには、次の設定を使用します。
# Make all loggers asynchronous
Log4jContextSelector = org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
AsyncLogger.RingBufferSize = 262144
AsyncLogger.WaitStrategy = Timeout
AsyncLogger.ThreadNameStrategy = CACHED
AsyncLogger.ExceptionHandler = default handler
その後、それはすべての100.000ログエントリを書き込むことが7891ms程度かかります。
log4j2 documentationによれば、非同期ロガーは、同期ロガーのレートの6〜68倍でメッセージをログできるはずです。
設定が間違っていますか？
==更新1 ==
途中でいくつかの変更がありました。 log4j.propertiesがlog4j2.xml
<?xml version="1.0" encoding="UTF-8"?>
<configuration status="error" name="JSONLogger">
<Properties>
<Property name="log-path">/Users/petervannes/NetBeansProjects/JSONLogger_2/logfiles</Property>
</Properties>
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%m%n" />
</Console>
<RollingRandomAccessFile name="RollingFile" fileName="${log-path}/jsonlogger.json"
filePattern="${log-path}/%d{yyyyMMdd}_jsonlogger-%i.json"
immediateFlush="false">
<PatternLayout>
<pattern>%m%n</pattern>
</PatternLayout>
<Policies>
<TimeBasedTriggeringPolicy />
<SizeBasedTriggeringPolicy size="10 MB" />
</Policies>
<DefaultRolloverStrategy max="4"/>
</RollingRandomAccessFile>
<Async name="Async">
<AppenderRef ref="RollingFile"/>
</Async>
</Appenders>
<Loggers>
<Logger name="JSONLogger" level="trace" additivity="false">
<AppenderRef ref="Async" />
</Logger>
<Root level="fatal">
<AppenderRef ref="Console" />
</Root>
</Loggers>
により置換されているシステムプロパティLog4jContextSelectorはlog4j2.component.propertiesから取り出し、現在のMavenシェードプラグインを使用して設定されています。以下のJUnitテストを実行する
<plugin>
<groupId>org.apache.maven.plugins</groupId>
<artifactId>maven-surefire-plugin</artifactId>
<version>2.19.1</version>
<configuration>
<encoding>UTF-8</encoding>
<argLine>-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector</argLine>
</configuration>
</plugin>
付きまたはLog4jContextSelectorシステムプロパティを設定せずに、今、多かれ少なかれ、同じ性能の結果が得られます。
@Test
public void orderD_logDebugMessageXMLToJSONFileTest() {
SecureRandom random = new SecureRandom();
String randomString = new BigInteger(130, random).toString();
String xmlString = "<logMessage xmlns=\"http://reddipped.com/jsonlogger\">\n"
+ " <Application>Application Name</Application>\n"
+ " <UserName>User Name</UserName>\n"
+ " <Identifier><FileID>F_" + randomString + "</FileID></Identifier>\n"
+ " <CorrelationID>" + randomString + "</CorrelationID>\n"
+ "</logMessage>";
int messages = 100000;
long start = System.nanoTime();
for (int x = 0; x < messages; x++) {
// Write a debug entry
SoaJSONLogger.getInstance().error(xmlString);
}
Long stop = System.nanoTime();
Long msgsPerSecond = messages/TimeUnit.NANOSECONDS.toSeconds((stop - start));
System.out.println("Messages/s : " + msgsPerSecond) ;
System.out.println("Duration : " + (stop - start)) ;
Assume.assumeTrue("Slow performance " + msgsPerSecond + " < 10000 ", msgsPerSecond >= 10000);
}
すべての結果は、周りの メッセージ/ sである：私はクラスパスとLog4jContextSelectorシステムプロパティからかく乱ジャーを削除した場合10630754228
==アップデート2 ==
：10000 期間パフォーマンスは依然として約10000メッセージ/秒です。瓶やシステムプロパティを復元し、システムにロガーの出力をトレースするlog4j2.xmlに素子構成の属性のステータスを設定することが
2017-01-23 21:45:14,392 main DEBUG LoggerContext[[email protected], [email protected]] started OK.
2017-01-23 21:45:14,393 main DEBUG AsyncLogger.ThreadNameStrategy=CACHED
2017-01-23 21:45:18,961 AsyncAppender-Async TRACE DefaultRolloverStrategy.purge() took 2.0 milliseconds
2017-01-23 21:45:18,966 AsyncAppender-Async DEBUG RollingFileManager executing synchronous FileRenameAction[/Users/petervannes/NetBeansProjects/JSONLogger_2/logfiles/jsonlogger.json to /Users/petervannes/NetBeansProjects/JSONLogger_2/logfiles/20170123_jsonlogger-1.json, renameEmptyFiles=false]
2017-01-23 21:45:18,972 AsyncAppender-Async TRACE Renamed file /Users/petervannes/NetBeansProjects/JSONLogger_2/logfiles/jsonlogger.json to /Users/petervannes/NetBeansProjects/JSONLogger_2/logfiles/20170123_jsonlogger-1.json with Files.move
2017-01-23 21:45:21,987 AsyncAppender-Async TRACE DefaultRolloverStrategy.purge() took 0.0 milliseconds
2017-01-23 21:45:21,991 AsyncAppender-Async DEBUG RollingFileManager executing synchronous FileRenameAction[/Users/petervannes/NetBeansProjects/JSONLogger_2/logfiles/jsonlogger.json to /Users/petervannes/NetBeansProjects/JSONLogger_2/logfiles/20170123_jsonlogger-2.json, renameEmptyFiles=false]
2017-01-23 21:45:21,991 AsyncAppender-Async TRACE Renamed file /Users/petervannes/NetBeansProjects/JSONLogger_2/logfiles/jsonlogger.json to /Users/petervannes/NetBeansProjects/JSONLogger_2/logfiles/20170123_jsonlogger-2.json with Files.move
iは唯一のロガーがあると結論づけることができることに基づいて示し
非同期です。パフォーマンスだけが同じです。
==アップデート3 ==
はのRandomAccessFileでRollingRandomAccessFileを置き換え。
<Properties>
<Property name="log-path">/Users/petervannes/NetBeansProjects/JSONLogger_2/logfiles</Property>
</Properties>
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%m%n" />
</Console>
<RandomAccessFile name="RollingFile" fileName="${log-path}/jsonlogger.json">
<PatternLayout>
<pattern>%m%n</pattern>
</PatternLayout>
<Policies>
<TimeBasedTriggeringPolicy />
<SizeBasedTriggeringPolicy size="10 MB" />
</Policies>
<DefaultRolloverStrategy max="4"/>
</RandomAccessFile>
<Async name="Async">
<AppenderRef ref="RollingFile"/>
</Async>
</Appenders>
<Loggers>
<Logger name="JSONLogger" level="trace" additivity="false">
<AppenderRef ref="Async" />
<!--<AppenderRef ref="Console" />-->
</Logger>
<Root level="fatal">
<AppenderRef ref="Console" />
</Root>
</Loggers>
ループの外SoaJSONLoggerのインスタンスを作成し、いくつかの 'ウォームアップ' のログイベントを追加しました。
int messages = 100000;
SoaJSONLogger l = SoaJSONLogger.getInstance() ;
l.error(xmlString);l.error(xmlString);l.error(xmlString);l.error(xmlString);l.error(xmlString);
long start = System.nanoTime();
for (int x = 0; x < messages; x++) {
// Write a debug entry
l.error(xmlString);
}
Long stop = System.nanoTime();
性能の変化はありません。 メッセージ/秒：10000 期間：10996023059
==更新4 ==レムコに追加
は
// plain logger
org.apache.logging.log4j.Logger log4j2Logger = org.apache.logging.log4j.LogManager.getLogger("JSONLogger") ;
log4j2Logger.error(xmlString);
long startl = System.nanoTime();
for (int x = 0; x < messages; x++) {
// Write a debug entry
log4j2Logger.error(xmlString);
}
Long stopl = System.nanoTime();
System.out.println("startl : " + startl) ;
System.out.println("stopl : " + stopl) ;
Long msgsPerSecondl = (long) 0 ;
if (TimeUnit.NANOSECONDS.toSeconds(stopl - startl) == 0) {
msgsPerSecondl = (long) messages ;
} else {
msgsPerSecondl = messages/TimeUnit.NANOSECONDS.toSeconds((stopl - startl));
}
System.out.println("Messages/s : " + msgsPerSecondl) ;
System.out.println("Duration : " + (stopl - startl)) ;
// plain logger end
パフォーマンスは、今100000メッセージ/秒（10倍、以前のパフォーマンス）
でテストコードを示唆しました
これを測定している方法は？あなたが言及した時間には、JVMの起動とLog4j2の初期化時間も含まれますか？ –
これはかなり前のことでしたが、私はSystem.nanoTime（）を保存してこれを測定しました。ログエントリを繰り返し書き込む前にちょうど – pcvnes
の質問を更新しました。アップデート2を参照してください。 – pcvnes