亞寵展、全球寵物產業風向標——亞洲寵物展覽會深度解析
607
2022-05-28
日交易額百億級交易系統的超輕量日志實現
首先來聊聊往事吧~~兩年前就職于一家傳統金融軟件公司，為某交易所開發一套大型交易系統，交易標的的價格為流式數據，采用價格觸發成交方式，T+0交易制度（類似炒股，只是炒的不是股票而是其他標的物，但可以隨時開平倉）。鑒于系統需要記錄大量價格數據、交易信息及訂單流水，且系統對性能要求極高（敏感度達毫秒級），因此需要避免日志服務成為系統性能瓶頸。通過對幾個通用型日志（如log4j、logback）的性能壓測，以及考慮到它們作為通用型日志相對比較臃腫，就決定自個兒寫個日志工具以支撐系統功能和性能所需。當時的做法只是簡單的將日志的實現作為一個 util 類寫在項目中，只有幾百行的代碼量。
系統上線兩個月后日均成交額200億RMB，最高達440億RMB，峰值成交4000筆/秒。系統非常龐大，但幾百行的代碼卻完美支撐住了重要的日志服務！
鑒于其優秀的表現，就花了一點點時間把它抽取出來作為一個獨立的日志組件，取名叫 FLogger，代碼幾乎沒有改動，現已托管到GitHub（FLogger），有興趣的童鞋可以clone下來了解并改進，目前它的實現是非常簡（純）單（粹）的。
以上就是 FLogger 的誕生背景。好吧，下面進入正題。
特性
雖然 FLogger 只有幾百行的代碼，但是麻雀雖小五臟俱全，它可是擁有非常豐富的特性呢：
雙緩沖隊列
多種刷盤機制，支持時間觸發、緩存大小觸發、服務關閉強制觸發等刷盤方式
多種 RollingFile 機制，支持文件大小觸發、按天觸發等 Rolling 方式
多日志級別，支持 debug、info、warn、error和 fatal 等日志級別
熱加載，由日志事件觸發熱加載
超輕量，不依賴任何第三方庫
性能保證，成功用于日交易額百億級交易系統
使用
既然是個超輕量級日志，使用肯定要很簡單。為最大程度保持用戶的使用習慣，Flogger 提供了與 log4j 幾乎一樣的日志 API。你只需要先獲取一個實例，接下來的使用方式就非常簡單了：
?
1
2
3
4
5
6
7
8
//獲取單例
FLogger logger = FLogger.getInstance();
//簡便api,只需指定內容
logger.info( "Here is your message..." );
//指定日志級別和內容，文件名自動映射
logger.writeLog(Constant.INFO, "Here is your customized level message..." );
//指定日志輸出文件名、日志級別和內容
logger.writeLog( "error" , Constant.ERROR, "Here is your customized log file and level message..." );
使用前你需要在項目根路徑下創建 log.properties 文件，配置如下：
?
1
2
3
4
5
6
7
8
9
10
11
12
13
14
########## 公共環境配置 ##########
# 字符集
CHARSET_NAME = UTF-8
########## 日志信息配置 ##########
# 日志級別?? 0:調試信息? 1:普通信息?? 2:警告信息? 3:錯誤信息? 4:嚴重錯誤信息
LOG_LEVEL = 0,1,2,3,4
# 日志文件存放路徑
LOG_PATH =./log
# 日志寫入文件的間隔時間(默認為1000毫秒)
WRITE_LOG_INV_TIME = 1000
# 單個日志文件的大小(默認為10M)
SINGLE_LOG_FILE_SIZE = 10485760
# 單個日志文件緩存的大小(默認為10KB)
SINGLE_LOG_CACHE_SIZE = 10240
當然，為了提供最大程度的便捷性，日志內部針對所有配置項都提供了默認值，你大可不必擔心缺少配置文件會拋出異常。
至此，你可能很好奇使用 FLogger 打印出來的日志格式到底是怎樣的，會不會雜亂無章無法理解，還是信息不全根本無法判斷上下文呢？好吧，你多慮了，FLogger 提供了非常規范且實用的日志格式，能使讓你很容易理解且找到相關上下文。
先來看看上面的 demo 代碼打印出來的結果：
info.log
?
1
[INFO] 2016-12-06 21:07:32:840 [main] Here is your message...
warn.log
?
1
[WARN] 2016-12-06 21:07:32:842 [main] Here is your customized level message...
error.log
?
1
[ERROR] 2016-12-06 21:07:32:842 [main] Here is your customized log file and level message...
從上面可以看到，你可以很清楚的分辨出日志的級別、時間和內容等信息。到這其實很明了了，日志由以下幾個元素組成：
?
1
[日志級別] 精確到毫秒的時間 [當前線程名] 日志內容
當然，處于便捷性的考慮，FLogger 目前并不支持用戶定義日志格式，畢竟它的目的也不是要做成一個通用性或者可定制性非常高的日志來使用。
源碼解析
上面這么多都是圍繞如何使用進行說明，下面就針對 FLogger 的特性進行實現邏輯的源碼解析。
雙緩沖隊列
FLogger 在內部采用雙緩沖隊列，那何為雙緩沖隊列呢？它的作用又是什么呢？
FLogger 為每個日志文件維護了一個內部對象?LogFileItem ，定義如下：
?
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
public class LogFileItem {
/** 不包括路徑，不帶擴展名的日志文件名稱 如：MsgInner */
public String logFileName = "" ;
/** 包括路徑的完整日志名稱 */
public String fullLogFileName = "" ;
/** 當前日志文件大小 */
public long currLogSize = 0;
/** 當前正在使用的日志緩存 */
public char currLogBuff = 'A' ;
/** 日志緩沖列表A */
public ArrayList
/** 日志緩沖列表B */
public ArrayList
/** 下次日志輸出到文件時間 */
public long nextWriteTime = 0 ;
/** 上次寫入時的日期 */
public String lastPCDate = "" ;
/** 當前已緩存大小 */
public long currCacheSize = 0;
}
在每次寫日志時，日志內容作為一個 StringBuffer 添加到當前正在使用的 ArrayList
關鍵代碼如下：
日志接收代碼
?
1
2
3
4
5
6
7
8
9
//同步單個文件的日志
synchronized(lfi){
if (lfi.currLogBuff == 'A' ){
lfi.alLogBufA.add(logMsg);
} else {
lfi.alLogBufB.add(logMsg);
}
lfi.currCacheSize += CommUtil.StringToBytes(logMsg.toString()).length;
}
日志刷盤代碼：
?
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
//獲得需要進行輸出的緩存列表
ArrayList
synchronized(lfi){
if (lfi.currLogBuff == 'A' ){
alWrtLog = lfi.alLogBufA;
lfi.currLogBuff = 'B' ;
} else {
alWrtLog = lfi.alLogBufB;
lfi.currLogBuff = 'A' ;
}
lfi.currCacheSize = 0;
}
//創建日志文件
createLogFile(lfi);
//輸出日志
int iWriteSize = writeToFile(lfi.fullLogFileName,alWrtLog);
lfi.currLogSize += iWriteSize;
多刷盤機制
FLogger 支持多種刷盤機制：
刷盤時間間隔觸發
內存緩沖大小觸發
退出強制觸發
下面就來一一分析。
配置項如下：
?
1
2
# 日志寫入文件的間隔時間(默認為1000毫秒)
WRITE_LOG_INV_TIME = 1000
當距上次刷盤時間超過間隔時間，將執行內存日志刷盤。
配置項如下：
?
1
2
# 單個日志文件緩存的大小(默認為10KB)
SINGLE_LOG_CACHE_SIZE = 10240
當內存緩沖隊列的大小超過配置大小時，將執行內存日志刷盤。
FLogger 內部注冊了 JVM 關閉鉤子 ShutdownHook ，當 JVM 正常關閉時，由鉤子觸發強制刷盤，避免內存日志丟失。相關代碼如下：
?
1
2
3
4
5
6
7
8
public FLogger(){
Runtime.getRuntime().addShutdownHook( new Thread( new Runnable() {
@Override
public void run() {
close();
}
}));
}
當 JVM 異常退出時無法保證內存中的日志全部落盤，但可以通過一種妥協的方式來提高日志刷盤的實時度：設置 SINGLE_LOG_CACHE_SIZE = 0 或者?WRITE_LOG_INV_TIME = 0 。
刷盤代碼如下：
?
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
/** 線程方法 */
public void run(){
int i = 0 ;
while (bIsRun){
try {
//輸出到文件
flush( false );
//重新獲取日志級別
if (i++ % 100 == 0){
Constant.CFG_LOG_LEVEL = CommUtil.getConfigByString( "LOG_LEVEL" , "0,1,2,3,4" );
i = 1;
}
} catch (Exception e){
System. out .println( "開啟日志服務錯誤..." );
e.printStackTrace();
}
}
}
/** 關閉方法 */
public void close(){
bIsRun = false ;
try {
flush( true );
} catch (Exception e){
System. out .println( "關閉日志服務錯誤..." );
e.printStackTrace();
}
}
/**
* 輸出緩存的日志到文件
* @param bIsForce 是否強制將緩存中的日志輸出到文件
*/
private void flush(boolean bIsForce) throws IOException{
long currTime = System.currentTimeMillis();
Iterator
while (iter.hasNext()){
LogFileItem lfi = logFileMap. get (iter.next());
if (currTime >= lfi.nextWriteTime || SINGLE_LOG_CACHE_SIZE <= lfi.currCacheSize || bIsForce == true ){
//獲得需要進行輸出的緩存列表
ArrayList
synchronized(lfi){
if (lfi.currLogBuff == 'A' ){
alWrtLog = lfi.alLogBufA;
lfi.currLogBuff = 'B' ;
} else {
alWrtLog = lfi.alLogBufB;
lfi.currLogBuff = 'A' ;
}
lfi.currCacheSize = 0;
}
//創建日志文件
createLogFile(lfi);
//輸出日志
int iWriteSize = writeToFile(lfi.fullLogFileName,alWrtLog);
lfi.currLogSize += iWriteSize;
}
}
}
多 RollingFile 機制
同 log4j/logback，FLogger 也支持多種 RollingFile 機制：
按文件大小?Rolling
按天?Rolling
其中按文件大小 Rolling，配置項為：
?
1
2
# 單個日志文件的大小(默認為10M)
SINGLE_LOG_FILE_SIZE = 10485760
即當文件大小超過配置大小時，將創建新的文件記錄日志，同時重命名舊文件為"日志文件名_日期_時間.log"（如 info_20161208_011105.log）。
按天 Rolling 即每天產生不同的文件。
產生的日志文件列表可參考如下：
?
1
2
3
4
5
info_20161207_101105.log
info_20161207_122010.log
info_20161208_011110.log
info_20161208_015010.log
info.log
當前正在寫入的日志文件為 info.log。
關鍵代碼如下：
?
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
/**
* 創建日志文件
* @param lfi
*/
private void createLogFile(LogFileItem lfi){
//當前系統日期
String currPCDate = TimeUtil.getPCDate( '-' );
//如果超過單個文件大小，則拆分文件
if (lfi.fullLogFileName != null && lfi.fullLogFileName.length() > 0 && lfi.currLogSize >= LogManager.SINGLE_LOG_FILE_SIZE ){
File oldFile = new File(lfi.fullLogFileName);
if (oldFile.exists()){
String newFileName = Constant.CFG_LOG_PATH + "/" + lfi.lastPCDate + "/" + lfi.logFileName + "_" + TimeUtil.getPCDate() + "_" + TimeUtil.getCurrTime() + ".log" ;
File newFile = new File(newFileName);
boolean flag = oldFile.renameTo(newFile);
System.out.println( "日志已自動備份為 " + newFile.getName() + ( flag ? "成功!" : "失敗!" ) );
lfi.fullLogFileName = "" ;
lfi.currLogSize = 0 ;
}
}
//創建文件
if ( lfi.fullLogFileName == null || lfi.fullLogFileName.length() <= 0 || lfi.lastPCDate.equals(currPCDate) == false ){
String sDir = Constant.CFG_LOG_PATH + "/" + currPCDate ;
File file = new File(sDir);
if (file.exists() == false ){
file.mkdir();
}
lfi.fullLogFileName = sDir + "/" + lfi.logFileName + ".log" ;
lfi.lastPCDate = currPCDate;
file = new File(lfi.fullLogFileName);
if (file.exists()){
lfi.currLogSize = file.length();
} else {
lfi.currLogSize = 0 ;
}
}
}
多日志級別
FLogger 支持多種日志級別：
DEBUG
INFO
WARN
ERROR
FATAL
FLogger 為每個日志級別都提供了簡易 API，在此就不再贅述了。
打印 error 和 fatal 級別日志時，FLogger 默認會將日志內容輸出到控制臺。
熱加載
FLogger 支持熱加載，FLogger 內部并沒有采用事件驅動方式（即新增、修改和刪除配置文件時產生相關事件通知 FLogger 實時熱加載），而是以固定頻率的方式進行熱加載，具體實現就是每執行完100次刷盤后才進行熱加載（頻率可調），關鍵代碼如下：
?
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
int i = 0 ;
while (bIsRun){
try {
//等待一定時間
Thread.sleep( 200 );
//輸出到文件
flush( false );
//重新獲取日志級別
if (i++ % 100 == 0 ){
Constant.CFG_LOG_LEVEL = CommUtil.getConfigByString( "LOG_LEVEL" , "0,1,2,3,4" );
//其他配置項熱加載......
i = 1 ;
}
} catch (Exception e){
System.out.println( "開啟日志服務錯誤..." );
e.printStackTrace();
}
}
這么做完全是為了保持代碼的精簡和功能的純粹性。事件驅動熱加載無疑是更好的熱加載方式，但需要新建額外的線程并啟動對配置文件的事件監聽，有興趣的童鞋可自行實現。
性能保證
FLogger 成功支撐了日交易額百億級交易系統的日志服務，它的性能是經歷過考驗的。下面我們就來拿 FLogger 跟 log4j 做個簡單的性能對比。
測試環境：Intel(R) Core(TM) i5-3470 CPU @ 3.20GHz ?3.20 GHz ? 4.00 GB Memory ? 64位操作系統
測試場景：單條記錄72byte ? 共1000000條 ? 寫單個日志文件
FLogger 配置如下：
?
1
2
3
4
5
6
# 日志寫入文件的間隔時間
WRITE_LOG_INV_TIME = 0
# 單個日志文件的大小
SINGLE_LOG_FILE_SIZE = 104857600
# 單個日志文件緩存的大小
SINGLE_LOG_CACHE_SIZE = 0
以上配置保證所有日志寫入到單個文件，且盡量保證每一條記錄不在內存中緩存，減少測試誤差。
測試代碼：
?
1
2
3
4
5
6
7
8
9
FLogger logger = FLogger.getInstance();??? //FLogger
//Logger logger = Logger.getLogger(Log4jTest.class);?? //log4j
String record = "Performance Testing about log4j and cyfonly customized java project log." ;?? //72字節
long st = System.currentTimeMillis();
for ( int i=0; i<1000000; i++){
logger.info(record);
}
long et = System.currentTimeMillis();
System. out .println( "FLogger/log4j write 1000000 records with each record 72 bytes, cost :" + (et - st) + " millseconds" );
日志內容：
?
1
2
3
4
5
FLogger:
[INFO] 2016 - 12 - 06 21 : 40 : 06 : 842 [main] Performance Testing about log4j and cyfonly customized java project log.
log4j:
[INFO ] 2016 - 12 - 06 21 : 41 : 12 , 852 , [main]Log4jTest: 12 , Performance Testing about log4j and cyfonly customized java project log.
測試結果（執行10次取平均值）：
?
1
2
FLogger write 1000000 records with each record 72 bytes, cost : 2144 millseconds
log4j write 1000000 records with each record 72 bytes, cost :cost : 12691 millseconds
說明：測試結果為日志全部刷盤成功的修正時間，加上各種環境的影響，有少許誤差，在此僅做簡單測試，并不是最嚴格最公平的測試對比。有興趣的童鞋可進行精確度更高的測試。
任務調度
版權聲明：本文內容由網絡用戶投稿，版權歸原作者所有，本站不擁有其著作權，亦不承擔相應法律責任。如果您發現本站中有涉嫌抄襲或描述失實的內容，請聯系我們jiasou666@gmail.com 處理，核實后本網站將在24小時內刪除侵權內容。
相關文章
