Upgrade to Pro
— share decks privately, control downloads, hide ads and more …
Speaker Deck
Features
Speaker Deck
PRO
Sign in
Sign up for free
Search
Search
LogbackからLog4j 2への移行によるアプリケーションのスループット改善 ( JJUG CCC 2021 Fall )
Search
hiroisojp
November 21, 2021
Programming
0
44
LogbackからLog4j 2への移行によるアプリケーションのスループット改善 ( JJUG CCC 2021 Fall )
JJUG CCC 2021 Fall の発表資料です。
(SlideShareより移行)
hiroisojp
November 21, 2021
Tweet
Share
More Decks by hiroisojp
See All by hiroisojp
Foreign Function & Memory API ( FFM API )を用いたNativeライブラリ呼び出しと既存ライブラリの比較 ( JJUG CCC 2023 Fall )
hiroisojp
1
660
JVMパラメータチューニングにおけるOptunaの活用事例 ( Optuna Meetup #1 )
hiroisojp
0
8
オンライン広告入札システムとZGC ( JJUG CCC 2021 Spring )
hiroisojp
0
15
200,000 Req/sec をさばく広告入札システムを支えるパフォーマンスチューニング術 #jjug_ccc #ccc_g6
hiroisojp
0
6
Logicadの秒間16万リクエストをさばく広告入札システムにおける、gRPCの活用事例 ( JJUG CCC 2018 Spring )
hiroisojp
0
6
Other Decks in Programming
See All in Programming
Introduction of Happy Eyeballs Version 2 (RFC8305) to the Socket library
coe401_
1
220
Play Billing Library 7.0.0 変更点まとめ@potatotips#88
kako351
0
160
Composing an API the *right* way (Droidcon Berlin 2024)
zsmb
1
450
TiDB Serverless ~理想のServerless DBを考える~
soso_15315
1
160
初心者がおさえておきたいAWS CDKのベストプラクティス 2024
konokenj
15
7.3k
AWSでゲームサーバーを運用! Amazon GameLiftのお話
iriikeita
0
200
Javaの現状2024夏 / Java current status 2024 summer
kishida
4
1.4k
CSC307 Lecture 12
javiergs
PRO
0
220
AWS初心者ってどうやってAWSを学ぶ?〜アプリエンジニアがやってよかったアーキテクチャ学習方法〜
yamanashi_ren01
0
190
Cloudflare Workers x AWS Lambdaの組み合わせユースケース / Cloudflare Workers x AWS Lambda Combination Use Case
seike460
PRO
2
310
Microservices rules (July 2024) : what good looks like
cer
PRO
0
1.6k
実用的かつリーズナブルな 「Azure × Gemini × LINE」~キャラクターBot 実装ライブデモ~
tomodo_ysys
1
170
Featured
See All Featured
Exploring the Power of Turbo Streams & Action Cable | RailsConf2023
kevinliebholz
12
3.8k
Save Time (by Creating Custom Rails Generators)
garrettdimon
PRO
13
430
Code Reviewing Like a Champion
maltzj
517
39k
How STYLIGHT went responsive
nonsquared
93
5k
Building Applications with DynamoDB
mza
89
5.8k
GraphQLとの向き合い方2022年版
quramy
36
13k
Testing 201, or: Great Expectations
jmmastey
33
6.9k
A Philosophy of Restraint
colly
200
16k
What the flash - Photography Introduction
edds
65
11k
Build your cross-platform service in a week with App Engine
jlugia
227
17k
Debugging Ruby Performance
tmm1
71
11k
In The Pink: A Labor of Love
frogandcode
139
22k
Transcript
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential LogbackからLog4j 2への移行による アプリケーションのスループット改善
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 1 アジェンダ 1.自己紹介 2.LogbackからLog4j 2へ変更した際のQPS 3.Log4j 2のloggerの特徴 4.アプリケーションでのベンチマーク結果 5.Log4j 2の注意事項 6.まとめ
ULS 2 Copyright © 2011-2021 UL Systems, Inc. All rights
reserved. Proprietary & Confidential 自己紹介
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 3 磯田 浩靖 - 所属:ウルシステムズ株式会社 - 連絡先:
[email protected]
- twitter:hiroisojp - Javaエンジニア、認定スクラムマスタ 自己紹介
ULS 4 Copyright © 2011-2021 UL Systems, Inc. All rights
reserved. Proprietary & Confidential LogbackからLog4j 2へ変更した際のQPS
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 5 LogbackからLog4j 2へ変更した際のQPS Logback Log4j 2 同じアプリケーションコードでロギングライブラリを変更した際のQPSが 20%程度向上した QPS = Queries Per Second、1秒間で処理できる件数
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 6 Log4j 2はLogbackとアーキテクチャが異なる - Log4j 2 はロックフリーのデータ構造 - 内部でLMAX Disruptorというライブラリを用い、Ring Bufferを使ったデータ構造 - Logback はロック競合あり - ArrayBlockingQueue この違いによりQPSに差が出たのではないかと思われる なぜQPSが向上したか https://www.slideshare.net/Stephan.Schmidt/lmax-architecture-jax-conference
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 7 マルチスレッドであるほどロックフリーの恩恵が大きい (参考)公式サイトのベンチマーク https://logging.apache.org/log4j/2.x/performance.html Logback Log4j 2
ULS 8 Copyright © 2011-2021 UL Systems, Inc. All rights
reserved. Proprietary & Confidential Log4j 2のloggerの特徴
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 9 Log4j2のloggerはsync/asyncがあり以下の組み合わせで設定できる all loggers asyncが最もパフォーマンスがよい 利用する場合はJVMパラメータを指定する - log4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector all loggers async 種類 設定方法 sync log4j2.xmlにLoggerとして指定 <Logger name="foo.Bar" level="info"></Logger> async log4j2.xmlにAsyncLoggerとして指定 <AsyncLogger name="foo.Baz" level="trace"></AsyncLogger> mixed sync/async log4j2.xmlにLogger, AsyncLoggerをそれぞれ指定 all loggers async log4j2.xmlにLoggerとして指定+以下のJVMオプションを指定 - Dlog4j2.contextSelector=org.apache.logging.log4j.core.async.As yncLoggerContextSelector all loggers asyncが 最もパフォーマンスがよい
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 10 Log4j 2(2.6以降)ではガベージフリーなロギングが可能 ログ出力におけるGCが発生しにくい ガベージフリーロギング メモリ割り当て が発生 メモリ割り当て がほとんどない 2.5 2.6 https://logging.apache.org/log4j/2.x/manual/garbagefree.html
ULS 11 Copyright © 2011-2021 UL Systems, Inc. All rights
reserved. Proprietary & Confidential アプリケーションでのベンチマーク結果
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 12 Log4j 2利用によるベンチマーク確認 ガベージフリーロギング all loggers async QPSが向上 するか GC傾向が 変化するか Log4j 2の特徴がアプリケーションにも寄与するかをベンチマークにて確認
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 13 オンライン広告入札を行うアプリケーション - 秒間40万件のリクエストを処理(1台あたりは5k〜7k程度) - 3〜5ms以内のレスポンス リクエストごとに分析基盤で用いるログを出力している アプリケーション概要
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 14 - 処理数 - 秒間5k〜7k - 1行あたりのサイズ - 1.6kb - ファイルサイズ - 1GB(1分間) - アプリケーションスレッド数 - 84(CPUコア数 * 3) アプリケーション概要(ログ周辺)
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 15 <appender name="ASYNC_FOO_LOG" class="ch.qos.logback.classic.AsyncAppender"> <appender-ref ref="FOO_LOG" /> <queueSize>20000</queueSize> <discardingThreshold>0</discardingThreshold> </appender> <appender name="FOO_LOG" class="ch.qos.logback.core.rolling.RollingFileAppender"> <file>foo.tsv</file> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <fileNamePattern>foo.%d{yyyy-MM-dd.HH-mm}.tsv </fileNamePattern> </rollingPolicy> <encoder> <pattern> <![CDATA[%d{yyyy-MM-dd HH:mm:ss.SSS z}¥t%msg%n]]> </pattern> </encoder> </appender> Log4j 2、Logbackの設定概要 いずれもAsync Loggerにてログ出力処理を行う Logback Log4j 2 <RollingFile name="FOO_LOG" fileName="foo" filePattern="foo.%d{yyyy- MM-dd.HH-mm}.tsv"> <PatternLayout> <Pattern> <![CDATA[%d{yyyy-MM-dd HH:mm:ss.SSS z}¥t%msg%n]]> </Pattern> </PatternLayout> <Policies> <TimeBasedTriggeringPolicy /> </Policies> </RollingFile> logback.xml log4j2.xml (all loggers asyncを使う設定) - Dlog4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLogger ContextSelector -DAsyncLogger.WaitStrategy=busyspin -DAsyncLogger.SynchronizeEnqueueWhenQueueFull=false JVMオプション
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 16 Log4j 2、Logbackを利用した時のQPS Logback Log4j 2 QPS = Queries Per Second、1秒間で処理できる件数 Log4j 2 = 約6,000QPS Logback = 約5,000QPS ロギングライブラリの変更により20%程度の向上がみられた
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 17 負荷をかけている内の1時間、JFRを取得しFlameGraphで確認 Log4j 2ではログ出力処理に関する部分が高速化された JFR(FlameGraph) Logback Log4j 2 幅が短いほうが、ある時間内の 処理時間の割合が低い=速い処理 Log4j 2より幅が広い = 処理に時間がかかっている
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 18 ログ出力処理のみにフォーカスすると LogbackではArrayBlockingQueue以降に時間を消費している JFR(FlameGraph) Logback Log4j 2
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 19 10-20ms帯ではややLog4j 2の方がGCが短い傾向がみられた GC傾向 Logback Log4j 2 Logbackより短いGC の割合が増えている
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 20 Log4j 2利用によるベンチマーク結果 ガベージフリーロギング all loggers async QPSが向上 するか GC傾向が 変化するか QPSは向上し、GC傾向も10-20ms帯でやや短くなる割合が増えた Logback時よりもQPSは向上した 10-20ms帯で改善が少しみられた
ULS 21 Copyright © 2011-2021 UL Systems, Inc. All rights
reserved. Proprietary & Confidential Log4j 2の注意事項
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 22 WaitStrategy、SynchronizeEnqueueWhenQueueFullの設定によっても FlameGraphの結果はかなり変わるのでアプリケーションにあった組み合わ せを探索する WaitStrategyの種類 - timeout(デフォルト) - block - sleep - yield - busyspin SynchronizeEnqueueWhenQueueFull - true/false all loggers asyncに関する注意事項 https://logging.apache.org/log4j/2.x/manual/async.html
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 23 WaitStrategy、SynchronizeEnqueueWhenQueueFullの組み合わせによる FlameGraphの例 all loggers asyncに関する注意事項 JVMパラメータ FlameGraph(赤枠内はlog4j 2の処理部分) AsyncLogger.WaitStrategy=busyspin AsyncLogger.SynchronizeEnqueueWhenQueueFull=false AsyncLogger.WaitStrategy=timeout AsyncLogger.WaitStrategy=busyspin AsyncLogger.SynchronizeEnqueueWhenQueueFull=true
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 24 Webアプリケーション(javax.servlet.Servletがクラスパスに存在する)の 場合、デフォルトは低ガベージモードとなる (log4j2.enable.threadlocalsがfalseに設定される) ガベージフリーに関する注意事項 https://logging.apache.org/log4j/2.x/manual/garbagefree.html JVMパラメータ モード log4j2.enable.threadlocals=true log4j2.enable.direct.encoders=true ガベージフリー log4j2.enable.threadlocals=false log4j2.enable.direct.encoders=true 低ガベージ log4j2.enable.threadlocals=false log4j2.enable.direct.encoders=false クラシック
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 25 ログ出力時に%d(日付)などPatternを指定し値を変換することができる このうち位置情報を含むPatternを用いるとパフォーマンスが大きく落ちる Patternに関する注意事項 Pattern 出力例 %C or %class foo.Bar %F or %file Bar.java %l or %location foo.Bar.exec(Bar.java:123) %L or %line 123 %M or %method exec 位置情報を含むPattern Asyncのときにも パフォーマンス影響 が大きい https://logging.apache.org/log4j/2.x/performance.html#asyncLoggingWithLocation
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 26 ほぼそのまま移行できたため、大きな問題はなかった アプリケーションで利用していた範囲ではif conditionのみ影響があった (設定ファイル自体を分けて対応) <if condition='property("type").contains("staging")'> <then> (ステージング環境用の設定) </then> <else> (本番環境用の設定) </else> </if> Log4j 2では左記のLogbackの ように条件分岐できない (参考)ログ設定ファイルの移行 logback.xml
ULS 27 Copyright © 2011-2021 UL Systems, Inc. All rights
reserved. Proprietary & Confidential まとめ
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 28 - アプリケーションのQPSが向上 & GCも多少改善した - Logbackからロギングライブラリの置き換えを試して見る価値あり - 何度か計測して同じ傾向であったことは確認済 - Log4j 2 Async, ガベージフリーの恩恵は設定や環境制約がある - WaitStrategyのチューニングをする - ガベージフリーはWebアプリケーションではデフォルトは低ガベージモードとなる ので、ガベージフリーモードが利用できるかをチェック - ログ出力時のPatternに位置情報を含めないようにする まとめ
ULS Copyright © 2011-2021 UL Systems, Inc. All rights reserved.
Proprietary & Confidential 29