日交易額百億級交易系統的超輕量日誌實現

時間  2019-11-24
標籤 交易額 百億 交易 系統 輕量 日誌 實現 简体版
原文   原文鏈接

首先來聊聊往事吧~~兩年前就任於一家傳統金融軟件公司，爲某交易所開發一套大型交易系統，交易標的的價格爲流式數據，採用價格觸發成交方式，T+0交易制度（相似炒股，只是炒的不是股票而是其餘標的物，但能夠隨時開平倉）。鑑於系統須要記錄大量價格數據、交易信息及訂單流水，且系統對性能要求極高（敏感度達毫秒級），所以須要避免日誌服務成爲系統性能瓶頸。經過對幾個通用型日誌（如log4j、logback）的性能壓測，以及考慮到它們做爲通用型日誌相對比較臃腫，就決定自個兒寫個日誌工具以支撐系統功能和性能所需。當時的作法只是簡單的將日誌的實現做爲一個 util 類寫在項目中，只有幾百行的代碼量。java

系統上線兩個月後日均成交額200億RMB，最高達440億RMB，峯值成交4000筆/秒。系統很是龐大，但幾百行的代碼卻完美支撐住了重要的日誌服務！git

鑑於其優秀的表現，就花了一點點時間把它抽取出來做爲一個獨立的日誌組件，取名叫 FLogger，代碼幾乎沒有改動，現已託管到GitHub（FLogger），有興趣的童鞋能夠clone下來了解並改進，目前它的實現是很是簡（純）單（粹）的。github

以上就是 FLogger 的誕生背景。好吧，下面進入正題。api

特性

雖然 FLogger 只有幾百行的代碼，可是麻雀雖小五臟俱全，它但是擁有很是豐富的特性呢：緩存

  • 雙緩衝隊列
  • 多種刷盤機制，支持時間觸發、緩存大小觸發、服務關閉強制觸發等刷盤方式
  • 多種 RollingFile 機制，支持文件大小觸發、按天觸發等 Rolling 方式
  • 多日誌級別，支持 debug、info、warn、error和 fatal 等日誌級別
  • 熱加載，由日誌事件觸發熱加載
  • 超輕量，不依賴任何第三方庫
  • 性能保證，成功用於日交易額百億級交易系統

使用

FLogger 已經發布到 maven 公共倉庫（版本更新信息請點此查看），請添加如下依賴（或直接在項目中引用 jar 包）：多線程

<dependency>
    <groupId>com.github.cyfonly</groupId>
    <artifactId>flogger</artifactId>
    <version>1.0.2</version>
</dependency>

既然是個超輕量級日誌，使用確定要很簡單。爲最大程度保持用戶的使用習慣，Flogger 提供了與 log4j 幾乎同樣的日誌 API。你只須要先獲取一個實例，接下來的使用方式就很是簡單了：maven

//獲取單例
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...");

Flogger 使用的配置文件名稱爲 flogger.properties，內部實現了靈活的配置文件加載機制。配置文件加載順序爲：ide

  • 項目根路徑
  • src/main/resources
  • 默認配置

配置項以下：工具

########## 公共環境配置 ##########
# 字符集
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

[INFO] 2016-12-06 21:07:32:840 [main] Here is your message...

warn.log

[WARN] 2016-12-06 21:07:32:842 [main] Here is your customized level message...

error.log

[ERROR] 2016-12-06 21:07:32:842 [main] Here is your customized log file and level message...

 從上面能夠看到，你能夠很清楚的分辨出日誌的級別、時間和內容等信息。到這其實很明瞭了，日誌由如下幾個元素組成：

[日誌級別] 精確到毫秒的時間 [當前線程名] 日誌內容

 固然，處於便捷性的考慮，FLogger 目前並不支持用戶定義日誌格式，畢竟它的目的也不是要作成一個通用性或者可定製性很是高的日誌來使用。

源碼解析

上面這麼多都是圍繞如何使用進行說明，下面就針對 FLogger 的特性進行實現邏輯的源碼解析。

雙緩衝隊列

FLogger 在內部採用雙緩衝隊列，那何爲雙緩衝隊列呢？它的做用又是什麼呢？

FLogger 爲每一個日誌文件維護了一個內部對象 LogFileItem ，定義以下：

public class LogFileItem {

	/** 不包括路徑，不帶擴展名的日誌文件名稱 如：MsgInner */
	public String logFileName = "";
	
	/** 包括路徑的完整日誌名稱 */
	public String fullLogFileName = "";
	
	/** 當前日誌文件大小 */
	public long currLogSize = 0;
	
	/** 當前正在使用的日誌緩存 */
	public char currLogBuff = 'A';
	
	/** 日誌緩衝列表A */
	public ArrayList<StringBuffer> alLogBufA = new ArrayList<StringBuffer>();
	
	/** 日誌緩衝列表B */
	public ArrayList<StringBuffer> alLogBufB = new ArrayList<StringBuffer>();
		
	/** 下第二天志輸出到文件時間 */
	public long nextWriteTime = 0 ;
	
	/** 上次寫入時的日期 */
	public String lastPCDate = "";
	
	/** 當前已緩存大小 */
	public long currCacheSize = 0;

}

在每次寫日誌時，日誌內容做爲一個 StringBuffer 添加到當前正在使用的 ArrayList<StringBuffer> 中，另外一個則空閒。當內存中的日誌輸出到磁盤文件時，會將當前使用的 ArrayList<StringBuffer> 與空閒的 ArrayList<StringBuffer> 進行角色交換，交換後以前空閒的 ArrayList<StringBuffer> 將接收日誌內容，而以前擁有日誌內容的 ArrayList<StringBuffer> 則用來輸出日誌到磁盤文件。這樣就能夠避免每次刷盤時影響日誌內容的接收（即所謂的 stop-the-world 效應）及多線程問題。流程以下：

關鍵代碼以下：

日誌接收代碼

//同步單個文件的日誌
synchronized(lfi){
　　　　if(lfi.currLogBuff == 'A'){
　　　　　　　　lfi.alLogBufA.add(logMsg);
　　　　}else{
　　　　　　　　lfi.alLogBufB.add(logMsg);
　　　　}
　　　　lfi.currCacheSize += CommUtil.StringToBytes(logMsg.toString()).length;
}

日誌刷盤代碼：

//得到須要進行輸出的緩存列表
ArrayList<StringBuffer> alWrtLog = null;
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 支持多種刷盤機制：

  • 刷盤時間間隔觸發
  • 內存緩衝大小觸發
  • 退出強制觸發

下面就來一一分析。

刷盤時間間隔觸發

配置項以下：

# 日誌寫入文件的間隔時間(默認爲1000毫秒)
WRITE_LOG_INV_TIME = 1000

當距上次刷盤時間超過間隔時間，將執行內存日誌刷盤。

內存緩衝大小觸發

配置項以下：

# 單個日誌文件緩存的大小(默認爲10KB)
SINGLE_LOG_CACHE_SIZE = 10240

當內存緩衝隊列的大小超過配置大小時，將執行內存日誌刷盤。

退出強制觸發

FLogger 內部註冊了 JVM 關閉鉤子 ShutdownHook ，當 JVM 正常關閉時，由鉤子觸發強制刷盤，避免內存日誌丟失。相關代碼以下：

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 。

刷盤代碼以下：

/** 線程方法 */
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<String> iter = logFileMap.keySet().iterator();
　　　　while(iter.hasNext()){
　　　　　　　　LogFileItem lfi = logFileMap.get(iter.next());
　　　　　　　　if(currTime >= lfi.nextWriteTime || SINGLE_LOG_CACHE_SIZE <= lfi.currCacheSize || bIsForce == true){
　　　　　　　　　　　　//得到須要進行輸出的緩存列表
　　　　　　　　　　　　ArrayList<StringBuffer> alWrtLog = null;
　　　　　　　　　　　　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，配置項爲：

# 單個日誌文件的大小(默認爲10M)
SINGLE_LOG_FILE_SIZE = 10485760

即當文件大小超過配置大小時，將建立新的文件記錄日誌，同時重命名舊文件爲"日誌文件名_日期_時間.log"（如 info_20161208_011105.log）。

按天 Rolling 即天天產生不一樣的文件。

產生的日誌文件列表可參考以下：

info_20161207_101105.log
info_20161207_122010.log
info_20161208_011110.log
info_20161208_015010.log
info.log

 當前正在寫入的日誌文件爲 info.log。

關鍵代碼以下：

/**
* 建立日誌文件
* @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次刷盤後才進行熱加載（頻率可調），關鍵代碼以下：

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();
　　　　}
}

這麼作徹底是爲了保持代碼的精簡和功能的純粹性。事件驅動熱加載無疑是更好的熱加載方式，但須要新建額外的線程並啓動對配置文件的事件監聽，有興趣的童鞋可自行實現。

性能保證

FLogger 成功支撐了日交易額百億級交易系統的日誌服務，它的性能和穩定性是經歷過考驗的。爲更加直觀地展現 FLogger 的性能，此處對其吞吐量進行測試。

首先肯定測試場景：

線程數：1,2,4,8,16,32
日誌內容主體大小：100bytes, 200bytes, 400bytes

 接着配置參數（未列出配置項使用默認值）：

# 日誌寫入文件的間隔時間(1000毫秒)
WRITE_LOG_INV_TIME = 1000
# 單個日誌文件的大小(100M)
SINGLE_LOG_FILE_SIZE = 104857600
# 單個日誌文件緩存的大小(100KB)
SINGLE_LOG_CACHE_SIZE = 102400

 而後編寫測試代碼（查看源碼），以下：

private static FLogger flogger = FLogger.getInstance();

private static String record_100_byte = "Performance Testing.Performance Testing.Performance Testing.Performance Testing.Performance Testing.";   //100字節
private static String record_200_byte = "...";   //200字節，爲方便展現此處以"..."代替
private static String record_400_byte = "...";   //400字節，爲方便展現此處以"..."代替
private static AtomicInteger messageCount = new AtomicInteger(0);
private static int count = 1000000;  //基準數值，以messageCount爲準
private static int threadNum = 1;  //1,2,4,8,16,32

public static void main(String[] args) throws InterruptedException{
	
	final CountDownLatch latch = new CountDownLatch(threadNum);
	
	long st = System.currentTimeMillis();
	for(int i=0; i<threadNum; i++){
		new Thread(new Runnable() {
			@Override
			public void run() {
				while(messageCount.get() < count){
					flogger.info(record_400_byte);
					messageCount.incrementAndGet();
				}
				latch.countDown();
			}
		}).start();
	}
	latch.await();
	long et = System.currentTimeMillis();
	
	System.out.println("messageCount=" + messageCount.get() + ", threadNum=" + threadNum + ", costTime=" + (et-st) +"ms, throughput=" + (1*1000*messageCount.get()/(et-st)));
	System.exit(0);
}

 每一個測試場景在保證相同測試環境（不可控因素除外）的狀況下，均進行10次測試並採用平均值做爲最終結果，以下：

 如對測試方法及結果有疑問、建議或異議，歡迎經過評論或私下交流，本人QQ：869827095。

相關文章
相關標籤/搜索
每日一句
    每一个你不满意的现在，都有一个你没有努力的曾经。
本站公眾號
   歡迎關注本站公眾號,獲取更多信息
聯繫我們 最近搜索 最新文章 沪ICP备13005482号-10 MyBatis教程 SQL 教程 MySQL教程 Java 教程 Thymeleaf 教程 Hibernate教程 Spring教程 Redis教程