首先來聊聊往事吧~~兩年前就職於一家傳統金融軟件公司，為某交易所開發一套大型交易系統，交易標的的價格為流式數據，采用價格觸發成交方式，T+0交易制度（類似炒股，只是炒的不是股票而是其他標的物，但可以隨時開平倉）。鑒於系統需要記錄大量價格數據、交易信息及訂單流水，且系統對性能要求極高（敏感度達毫秒級），因此需要避免日志服務成為系統性能瓶頸。通過對幾個通用型日志（如log4j、logback）的性能壓測，以及考慮到它們作為通用型日志相對比較臃腫，就決定自個兒寫個日志工具以支撐系統功能和性能所需。當時的做法只是簡單的將日志的實現作為一個 util 類寫在項目中，只有幾百行的代碼量。
系統上線兩個月后日均成交額200億RMB，最高達440億RMB，峰值成交4000筆/秒。系統非常龐大，但幾百行的代碼卻完美支撐住了重要的日志服務！
鑒於其優秀的表現，就花了一點點時間把它抽取出來作為一個獨立的日志組件，取名叫 FLogger，代碼幾乎沒有改動，現已托管到GitHub（FLogger），有興趣的童鞋可以clone下來了解並改進，目前它的實現是非常簡（純）單（粹）的。
以上就是 FLogger 的誕生背景。好吧，下面進入正題。
特性
雖然 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。你只需要先獲取一個實例，接下來的使用方式就非常簡單了：
//獲取單例
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，內部實現了靈活的配置文件加載機制。配置文件加載順序為：
- 項目根路徑
- 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。