2018年4月9日 星期一

c++ logging library comparison


結論:
了解各 logging library 的設計方式、優缺點、使用限制...
如果您不想自己寫,就選擇一個適合的。
或吸收別人的想法,設計一個適合自己的。

測試說明
  • spdlog
    • spdlog::set_async_mode(1048576);
    • spdlog::create("file_logger", "/tmp/spd-async.txt", false);
    • spdlog 使用 lock-free bounded queue 儲存 log 訊息:字串格式化後放在 async_msg::txt,然後將 async_msg 推入 queue,在另一 thread 執行儲存。
    • 由於我只想知道 lock-free queue 影響多大,為了避免 std::string 造成效率的干擾,所以修改 include/spdlog/details/async_log_helper.h(Ln: 97,102) : async_msg(const details::log_msg &m); 建構時不填入 logger_name 及 txt
  • mal(mini-async-log)
    • mal_cfg.queue.can_use_heap_q = true;
    • mal_cfg.queue.bounded_q_block_size = 1048576;
    • mal 使用 lazy format 的技巧:儲存要輸出的資料,然後在寫檔的 thread 才進行格式化字串
    • mal 使用混合式 lock-free queue: bounded queue + node based queue,如果一條 log 訊息超過 64 bytes 或bounded queue(可儲存 16,384 條) 已滿,則會分配記憶體然後用 node based queue
  • 其他說明:
    • 由於測試時沒有使用 sudo,所以 測試程式 的 mlockall() 沒有發揮作用。
    • fon9 使用 spinlock + yield,有興趣的人可以自行改成 spinlock + busyloop 或 std::mutex,但是結果不會比較好,程式碼 (Ln: 42-44)。
    • 由於 log 僅是 fon9 的一小部分,依目前測試結果來看,效率是可接受的,等到真有 log 效率上的需求時,再來深入研究其他優秀的 logging library 吧!
    • 瞬間大量資料考驗的有 queue 的效率、queue 滿載後的策略、log訊息寫入的效率...
    • 由於瞬間大量資料,讓系統變得複雜,所以使用慢速測試,來分析結果。


壓力測試 (每個 thread 10萬筆 log 訊息),詳細
平均延遲 (越低越好),X軸=Thread數量,Y軸=延遲時間(ns)。












慢速(冷系統)測試(每個 thread 1萬筆,每筆間隔 1ms)詳細結果
平均延遲 (越低越好),X軸=Thread數量,Y軸=延遲時間(ns)。














底下不算是分析,只能算是我的猜測

spdlog 在冷系統時為何會有這麼大的延遲? 大概是

  1. bounded queue 用了太多記憶體(可儲存 1M 條訊息,約 100MB),造成 CPU cache 的負擔太大,但是把 spdlog::set_async_mode(); 降低後幫助不大。
  2. 有太多額外工作?

我個人比較感興趣的是 mal 的低延遲:
由於每個 thread 每秒大約 1000 筆,對 mal 的 bounded queue 而言,壓力不大,
加上測試訊息的資料量小 (一條訊息 mal 僅使用 34 bytes,所以用不到 node based queue),
mal bounded queue 使用的記憶體僅 1M bytes,對 CPU cache 的壓力也不大,
所以 mal 可以有穩定的低延遲。