日誌組件優化報告

背景

目前項目組日誌組件存在如下問題：

1 日誌文件每寫一第二天志就打開關閉一次，存在性能浪費

2 日誌裏面獲取時間須要調用localtime、stat，在頻繁調用時該函數消耗cpu比較多

3 日誌組件獲取環境變量時未判斷是否成功，若是環境變量沒設置會引發程序core

4 日誌組件在寫日誌時，先初始化局部變量再判斷日誌級別，能夠優化

5 日誌組件裏面有很多處調用了sprintf、ReplaceEnvVar和strlen，其實能夠避免

6 日誌組件調用了大量不可重入函數，在信號處理函數中寫日誌可能引發core

改造方案

1 增長文件句柄緩存與輸出緩衝：

         增長一個環境變量HIGH_PERFORMANCE_LOG，默認值爲0，不啓用。

當HIGH_PERFORMANCE_LOG爲1時，每次打開日誌後將日誌文件名記錄到g_logInfo. sFullLogName，寫完日誌後暫時不執行fclose。

下次寫日誌時判斷待寫日誌文件名是否與g_logInfo. sFullLogName一致，若是一致則不用從新打開文件。不然先將日誌文件句柄關閉再進行打開日誌文件的流程。

增長一個環境變量HIGH_PERFORMANCE_LOG_CACHE，默認值爲0，不啓用。在HIGH_PERFORMANCE_LOG_CACHE和HIGH_PERFORMANCE_LOG都爲1時，寫完日誌後不當即執行刷新到磁盤（不調用fflush）

 

2 減小非必要系統函數調用：

增長函數localtime項目組代替原來的localtime，每次調用localtime項目組時先判斷是否與上次調用間隔超過1分鐘，若是沒超過則使用上次調用localtime返回的結果，若是超過則從新調用localtime而且將結果緩存起來待下次使用。這樣從原來一分鐘調用屢次localtime變成一分鐘調用一次。

修改函數CommonGetCurrentDate，首次調用時記錄當天起始秒數和次日起始秒數，而且將返回的日誌緩存起來。以後每次調用判斷時間是否當天範圍內，若是是則直接使用緩存返回，不然重複上面流程。樣從原來天調用屢次localtime變成一天調用一次。

 

增長環境變量LOG_SYSCALL_INTERVAL_TIMES，默認值爲100，每寫LOG_SYSCALL_INTERVAL_TIMES第二天志時才執行一次stat（若是緩存打開狀況，須要先調用fflush將日誌緩衝刷出），不須要每寫一第二天志就檢查一次。注意，因爲每100行才檢查一第二天志大小，因此會影響原來50m切換一第二天志文件的邏輯，不必定精確的在50m時切換，會略大一些。

 

3 獲取環境變量失敗增長默認值：

改造原來獲取環境變量的代碼，增長環境變量獲取失敗時使用默認值的邏輯，避免異常狀況下致使程序core

 

4 將判斷日誌級別的邏輯往前提：

進入寫日誌邏輯後，先判斷當前日誌級別是否須要輸出日誌，若是不須要則直接返回。減小非必要的變量初始化操做。

5 使用耗時較小的函數代替耗時長的函數：

日誌組件每次寫日誌時須要使用ReplaceEnvVar函數替換日誌文件路徑裏面的變量， 現改成在初始化時就調用ReplaceEnvVar將文件路徑變量替換完。後面寫日誌時使用ifNeedReplaceEnvVar判斷是否須要替換變量，若是不須要則不調用ReplaceEnvVar

把簡單的sprintf調用改成同功能其它函數代替，如將fprintf(fp, "\n")改成fputc ('\n', fp)

判斷字符串是否爲空，不使用strlen(str) == 0的寫法，改成str[0] == '\0'

非功能測試對比

測試寫20萬行日誌改造先後日誌組件消耗時間

 

                       

 

 

 

 

 

結果以下：

單位ms

	不設置環境變量	HIGH_PERFORMANCE_LOG=1	HIGH_PERFORMANCE_LOG=1 HIGH_PERFORMANCE_LOG_CACHE=1	HIGH_PERFORMANCE_LOG=1 HIGH_PERFORMANCE_LOG_CACHE=1 LOG_SYSCALL_INTERVAL_TIMES=1000
新WrtieLog	4836.7	1001.88	453.12	454.28
新HtLog	5603.4	1355.96	1253.96	1277.58
新DebugLog	7017.66	2600.98	2323.88	2333.98
舊WrtieLog	7388.92	7442.24	7196.72	7380.76
舊HtLog	7654.6	7712.28	7498.46	7655.82
舊DebugLog	9404.58	9431.44	8805.68	9049.94
效率比	0.65	0.13	0.06	0.06

（50次平均值  測試屢次結果誤差不大）

 

基準測試：

 

 

 

 

測試日誌記錄：

 

 

結論：

 

改造後日志組件性能有所提升，效率提升約44%~70%

 

須要注意HIGH_PERFORMANCE_LOG環境變量啓用的狀況，若是程序寫日誌過程當中日誌文件被刪除或者移走，程序不能即時發現，仍然會往原來的日誌文件寫日誌。

須要等到寫滿LOG_SYSCALL_INTERVAL_TIMES行日誌後纔會觸發日誌文件從新打開關閉功能。

 

callgrind分析狀況

 

 

後續優化計劃

若是之後日誌組件再次成爲性能瓶頸，能夠考慮如下優化：

1 使用linux文件映射進行日誌文件讀寫，代替現有的標準庫函數。這樣能夠減小數據拷貝。

2 寫日誌時使用流壓縮，邊寫日誌邊壓縮，減小磁盤消耗。

3 實在不行考慮異步落盤，先將日誌數據寫到共享內存，由專用的日誌進程寫到日誌文件。