淺析 - CocoaLumberjack 3.6 之 DatabaseLogger

這是 DDLog 源碼閱讀的最後一篇。本篇重點介紹 DDLogger 對數據庫存儲的支持，原理應該和 FileLogger 同樣，log 磁盤存儲的頻率，過時 log 的淘汰策略，以及 log 存儲的緩存策略等。

開始以前，建議你們回顧前兩篇文章，不少基本的概念本篇會直接忽略。

上篇：《淺析 CocoaLumberjack 之 DDLog》

中篇：《淺析 CocoaLumberjack 之 FileLogger》

DDAbstractDatabaseLogger

做爲抽象類，你能夠自由的根據項目所使用的數據庫類型來提供具體的子類實現。DDLog 在 Demo 中提供了 FMDBLogger 和 CoreDataLogger 的實踐，會在後面稍微介紹。 所以，dbLogger 主要是保證 log entify (message 對應的 SQL) 的讀寫策略。來看幾個暴露 property 的聲明，先來看第一組：

@property (assign, readwrite) NSUInteger saveThreshold; // 500
@property (assign, readwrite) NSTimeInterval saveInterval; // 60s
複製代碼

這兩個是用於控制 entities 寫入磁盤的頻率。畢竟咱們不能針對每一條 log 都執行 SQL 插入語句 (I/O 操做）。

• saveThreshold：當前未處理 entities 數量的閾值，默認 500 條；
• saveInterval：執行下一次寫入的時間間隔；

咱們能夠經過將這兩個的值歸零的方式來表示🈲️止對應的控制。固然，這裏不建議將兩個值都置零。

另外三個主要用於控制已保存 entities 的清除頻率，畢竟咱們可不肯用戶發現磁盤被咱們給寫滿了。

@property (assign, readwrite) NSTimeInterval maxAge; // 7 day
@property (assign, readwrite) NSTimeInterval deleteInterval; // 5 min
@property (assign, readwrite) BOOL deleteOnEverySave; // NO
複製代碼

• maxAge：日誌最多保留時長，默認爲 7 天；
• deleteInterval：過時日誌刪除的頻率，默認爲 5 分鐘；
• deleteOnEverySave：另一個可選項，用於控制每第二天志寫入時，是否須要進行過時日誌的清除。

一樣，maxAge 和 deleteInterval 也可經過置零來 disable 其功能。

Timer 的生命週期

既然是跟蹤日誌的寫入和擦除，timer 是少不了的。dbLogger 分別針對 save 和 delete 操做都分配了一個 dispatch_source_t 做爲 timer。對應的建立、更新、銷燬的方法以下：

Save	Delete
createSuspendedSaveTimer	createAndStartDeleteTimer
updateAndResumeSaveTimer	updateDeleteTimer
destroySaveTimer	destroyDeleteTimer

createSuspendedSaveTimer

SaveTimer 在執行 log 寫入操做的時候會先暫停，在寫入結束後從新恢復計時。這裏 DDLog 使用了 _saveTimerSuspended 做爲標識 (爲 NSInteger 類型) ，標記 timer 的狀態。

if ((_saveTimer == NULL) && (_saveInterval > 0.0)) {
    _saveTimer = dispatch_source_create(DISPATCH_SOURCE_TYPE_TIMER, 0, 0, self.loggerQueue);

    dispatch_source_set_event_handler(_saveTimer, ^{ 
        @autoreleasepool { [self performSaveAndSuspendSaveTimer]; } 
    });
    _saveTimerSuspended = -1;
}
複製代碼

• _saveInterval > 0.0 代表開啓了 ⏲️ 檢查 log 寫入任務；
• 爲 timer 設置了定時回調 performSaveAndSuspendSaveTimer ；

_saveTimerSuspended 的值有三種類型，分別對應 dispatch_source_t 的三個狀態：

value	description
-1	建立時的初始狀態： inactivited
0	被激活狀態：actived / resumed
1	被掛起狀態：suspended

因此 timer 被 create 時是處於未激活的暫停狀態。

updateAndResumeSaveTimer

激活或恢復 SaveTimer，恢復前會檢查 _unsavedTime 是否大於 0，_unsavedTime 爲每次執行 logMessage 時所記錄的當前時間。_unsavedTime 也就是 timer 恢復的 startTime。

if ((_saveTimer != NULL) && (_saveInterval > 0.0) && (_unsavedTime > 0)) {
    uint64_t interval = (uint64_t)(_saveInterval * (NSTimeInterval) NSEC_PER_SEC);
    dispatch_time_t startTime = dispatch_time(_unsavedTime, (int64_t)interval);

    dispatch_source_set_timer(_saveTimer, startTime, interval, 1ull * NSEC_PER_SEC);
    //... 激活 timer
}
複製代碼

激活計時器會重置 timer 的 startTime 和 interval。

恢復 timer 的邏輯，這裏對不一樣版本的 GCD API 作了兼容性的適配。在 macOS 10.12, iOS 10.0 以後，新出了 dispatch_activate API 區別於原有的 dispatch_resume。這裏面有一個坑須要注意一下，先來看看這兩個方法的文檔描述：

dispatch_activate

Suspends the invocation of blocks on a dispatch object.

新生成的 queue 或 source 默認爲 inactive 狀態，它們必須設置爲 active 後其關聯的 event handler 纔可能被invoke。

對於未激活的 dispatch objc 咱們能夠經過 dispatch_set_target_queue() 來更新初始化時綁定的 queue，一旦爲 active 話，這麼作就可能致使 crash，坑點 1。另外，dispatch_activate 對已激活的 dispatch objc 是沒有反作用的。

dispatch_resume

Resumes the invocation of blocks on a dispatch object.

dispatch source 經過 dispatch_suspend() 時，會增長內部的 suspension count，resume 則是相反操做。當 suspension count 清空後，註冊的 event handler 才能被再次觸發。

爲了向後兼容，對於 inactive 的 source 調用 dispatch_resume 的效果與 dispatch_active 一致。對於 inactive 的 source 建議使用 dispatch_activate 來激活。

若是對 suspension count 爲 0 且爲 inactive 狀態的 source 執行 dispatch_resume，則會觸發斷言被強制退出。

激活 Timer 實現以下，因此下面這段代碼對不一樣版本的 timer 的不一樣狀態作了區分。

if (@available(macOS 10.12, iOS 10.0, tvOS 10.0, watchOS 3.0, *)) {
    if (_saveTimerSuspended < 0) { /// inactive
        dispatch_activate(_saveTimer);
        _saveTimerSuspended = 0;
    } else if (_saveTimerSuspended > 0) { /// active
        dispatch_resume(_saveTimer);
        _saveTimerSuspended = 0;
    }
} else {
    if (_saveTimerSuspended != 0) { /// inactive
        dispatch_resume(_saveTimer);
        _saveTimerSuspended = 0;
    }
}
複製代碼

destroySaveTimer

銷燬 timer。首先執行 dispatch_source_cancel 將 timer 標記爲 cacneled 以取消以後的 event handler 的執行。以後將 timer 狀態標記爲 actived，不然在 release inactive 的 source 會致使 crash。

if (@available(macOS 10.12, iOS 10.0, tvOS 10.0, watchOS 3.0, *)) {
    if (_saveTimerSuspended < 0) {
        dispatch_activate(_saveTimer);
    } else if (_saveTimerSuspended > 0) {
        dispatch_resume(_saveTimer);
    }
} else {
    if (_saveTimerSuspended != 0) {
        dispatch_resume(_saveTimer);
    }
}
複製代碼

最後釋放：

#if !OS_OBJECT_USE_OBJC
dispatch_release(_saveTimer);
#endif
_saveTimer = NULL;
_saveTimerSuspended = 0;
複製代碼

createAndStartDeleteTimer

Delete Timer 的邏輯就比較簡單一些。因爲 log 清除的邏輯不須要像寫入同樣，在每次 logMessage 的時候都從新更新 startTime 並恢復爲 active 狀態。同時 Delete Timer 在初始化的時候就保證了其爲 active 狀態。因此 Delete Timer 在 update 的時候，也不須要再確保狀態爲 active。

if ((_deleteTimer == NULL) && (_deleteInterval > 0.0) && (_maxAge > 0.0)) {
    _deleteTimer = dispatch_source_create(DISPATCH_SOURCE_TYPE_TIMER, 0, 0, self.loggerQueue);

    if (_deleteTimer != NULL) {
        dispatch_source_set_event_handler(_deleteTimer, ^{ 
           @autoreleasepool { [self performDelete]; } 
        });

        [self updateDeleteTimer];

        if (@available(macOS 10.12, iOS 10.0, tvOS 10.0, watchOS 3.0, *))
            dispatch_activate(_deleteTimer);
        else
            dispatch_resume(_deleteTimer);
    }
}
複製代碼

updateDeleteTimer

更新 Delete Timer 時，會檢查是否執行過一次清除操做。若是有，會以上次清楚的時間戳做爲 startTime。

if ((_deleteTimer != NULL) && (_deleteInterval > 0.0) && (_maxAge > 0.0)) {
    int64_t interval = (int64_t)(_deleteInterval * (NSTimeInterval) NSEC_PER_SEC);
    dispatch_time_t startTime;

    if (_lastDeleteTime > 0) {
        startTime = dispatch_time(_lastDeleteTime, interval);
    } else {
        startTime = dispatch_time(DISPATCH_TIME_NOW, interval);
    }

    dispatch_source_set_timer(_deleteTimer, startTime, (uint64_t)interval, 1ull * NSEC_PER_SEC);
}
複製代碼

destroyDeleteTimer

if (_deleteTimer != NULL) {
    dispatch_source_cancel(_deleteTimer);
    #if !OS_OBJECT_USE_OBJC
    dispatch_release(_deleteTimer);
    #endif
    _deleteTimer = NULL;
}
複製代碼

Configuration

dbLogger 對寫入和清除操做控制策略的屬性進行了重載。這幾個 Access 方法的 getter 和 setter 都是線程安全的，它們都是在 loggingQueue 和 loggerQueue 中來執行操做的，具體能夠看 DDLog 上篇。getter 只是取值，所以這裏主要聊聊，其值更新時有哪些操做。

setSaveThreshold

更新 saveThreshold 後，須要檢查當前未寫入的 entities 數是否超過新賦值的閾值。若是超出須要主動執行寫入操做並更新 SaveTimer：

if ((self->_unsavedCount >= self->_saveThreshold) && (self->_saveThreshold > 0)) {
    [self performSaveAndSuspendSaveTimer];
}
複製代碼

setSaveInterval

更新下一次執行 log entries 的時間間隔。又出現新知識點了，這裏做者使用了 islessgreater 宏來判斷 saveInterval 是否有變化。這個 islessgreater 是 C99 標準中推薦的浮點數比較的宏:

The built-in operator< and operator> for floating-point numbers may raise FE_INVALID if one or both of the arguments is NaN. This function is a "quiet" version of the expression x < y || x > y. The macro does not evaluate x and y twice.

使用它能避免由於值爲 NaN 而出現的異常。關於浮點數的對比，這裏有一篇不錯的文章：comparison。

因爲 saveInterval 是否爲 0 是用於控制定時寫入功能，所以，更新後有三種狀況須要處理：

if (self->_saveInterval > 0.0) {
    if (self->_saveTimer == NULL) {

        [self createSuspendedSaveTimer];
        [self updateAndResumeSaveTimer];
    } else {

        [self updateAndResumeSaveTimer];
    }
} else if (self->_saveTimer) {

    [self destroySaveTimer];
}
複製代碼

• 須要開啓定時寫入且 timer 爲 NULL；須要建立 SaveTimer 並激活它；
• 須要開啓定時寫入且 timer 存在；激活並恢復 SaveTimer；
• 無需定時寫入：銷燬 Timer；

setMaxAge

maxAge 的狀況更多一些，有四種 case。在更新 maxAge 前，保留了舊值用於對比，一樣用到了 islessgreater。

BOOL shouldDeleteNow = NO;

if (oldMaxAge > 0.0) {
    if (newMaxAge <= 0.0) { /// 1
        [self destroyDeleteTimer];
       
    } else if (oldMaxAge > newMaxAge) {
        shouldDeleteNow = YES; /// 4
    }
} else if (newMaxAge > 0.0) {
    shouldDeleteNow = YES; /// 2
}

if (shouldDeleteNow) {
    [self performDelete];

    if (self->_deleteTimer) {
        [self updateDeleteTimer];
    } else {
        [self createAndStartDeleteTimer];
    }
}
複製代碼

1. maxAge 檢查從開啓變爲關閉狀態，此時只須要銷燬 Delete Timer；
2. maxAge 檢查從關閉變爲開啓狀態，須要當即清理過時日誌，並初始化 Delete Timer
3. 日誌保留時長增長，do nothing；
4. 日誌保留時長減小，須要當即清理；

setDeleteInterval

deleteInterval 同 saveInterval 對 timer 的操做邏輯相同，就不展開了。

Save & Delete

既然作爲抽象類，確定須要有幾個方法暴露給子類去實現，要不就是經過 protocol 讓 delegate 去實現。這裏 ddLogger 預留了四個虛方法：

- (BOOL)db_log:(__unused DDLogMessage *)logMessage {
	// Return YES if an item was added to the buffer.
	// Return NO if the logMessage was ignored.
	return NO;
}
- (void)db_save {}
- (void)db_delete {}
- (void)db_saveAndDelete {}
複製代碼

Public API

dbLogger 爲用戶主動執行寫入和清除提供了兩個方法 savePendingLogEntries 和 deleteOldLogEntries。

做爲 logger 的公共方法，其執行必須在 loggerQueue 中，以 savePendingLogEntries 爲例：

dispatch_block_t block = ^{
     @autoreleasepool {
         [self performSaveAndSuspendSaveTimer];
     }
 };

 if ([self isOnInternalLoggerQueue]) {
     block();
 } else {
     dispatch_async(self.loggerQueue, block);
 }
複製代碼

performSaveAndSuspendSaveTimer 則是其對應的 private method，一樣的 deleteOldLogEntries 對應的 private method 爲 performDelete 。

performSaveAndSuspendSaveTimer

從方法名可知這裏作了兩件事：執行日誌寫入和掛起 SaveTimer。

寫入前確保存在未寫入日誌，而後依據 _deleteOnEverySave 區分是否須要在每次寫入的同時進行清楚操做：

if (_unsavedCount > 0) {
    if (_deleteOnEverySave) {
        [self db_saveAndDelete];
    } else {
        [self db_save];
    }
}
/// 寫入結束重置狀態；
_unsavedCount = 0;
_unsavedTime = 0;
複製代碼

接着將 timer 掛起，等待下一次的 logMessage 以刷新 timer：

if (_saveTimer != NULL && _saveTimerSuspended == 0) {
    dispatch_suspend(_saveTimer);
    _saveTimerSuspended = 1;
}
複製代碼

須要注意，這裏使用 _saveTimerSuspended 做爲標記，防止屢次執行 dispatch_suspend 操做，同時也保證了 source 是處於 active 狀態。前面在 dispatch source 的狀態變動中提到，source 內部維護一個 suspension count，屢次執行會致使 count 增大。這裏算是一魚多吃了，👍。

performDelete

if (_maxAge > 0.0) {
    [self db_delete];

    _lastDeleteTime = dispatch_time(DISPATCH_TIME_NOW, 0);
}
複製代碼

開啓清楚操做的話就執行 delete，結束後更新 _lastDeleteTime。

DDLogger

在遵循 DDLogger 的方法中基本也是維護 timer 的狀態，觸發 save 操做。

didAddLogger

[self createSuspendedSaveTimer];
[self createAndStartDeleteTimer];
複製代碼

willRemoveLogger

[self performSaveAndSuspendSaveTimer];

[self destroySaveTimer];
[self destroyDeleteTimer];
複製代碼

logMessage

if ([self db_log:logMessage]) { /* 更新 save timer */  }
複製代碼

logMessage 方法是用戶產生 new log 所觸發的，包含了關鍵的 log message。在 FileLogger 中時將 message 轉換爲 NSData 調用 lt_logData 來寫入文件，而這裏則會將 message 轉換爲 log entity 以期寫入 DB 中。db_log 所作的真是和 lt_logData 一致的。

不過這裏留了一個開關，就是 db_log 的返回值。若是返回 NO 則意味着改條 log 被丟棄，咱們也不須要更新 timer 的 startTime 或者觸發 save 操做。

更新邏輯以下：

BOOL firstUnsavedEntry = (++_unsavedCount == 1);
if ((_unsavedCount >= _saveThreshold) && (_saveThreshold > 0)) {
    [self performSaveAndSuspendSaveTimer];
} else if (firstUnsavedEntry) {
    _unsavedTime = dispatch_time(DISPATCH_TIME_NOW, 0);
    [self updateAndResumeSaveTimer];
}
複製代碼

flush

[self performSaveAndSuspendSaveTimer];
複製代碼

該方法是當應用退出或崩潰時主動調用，以及時保存還在 pendding 狀態的 log entities。

FMDBLogger

簡單介紹一下 FMDBLogger，它是經過 FMDB 提供的 API 將 log message 寫入數據庫。

這裏每條 DDLogMessage 對應爲 FMDBLogEntry，它簡單存儲了 context、flag、message、timestamp。數據庫建表和校驗就不說了，主要圍繞重載的幾個方法。

db_log

FMDBLogEntry *logEntry = [[FMDBLogEntry alloc] initWithLogMessage:logMessage];
[pendingLogEntries addObject:logEntry];
複製代碼

這裏並無直接將 logEntry 插入 db，而是添加到緩衝列表中。咱們真的須要這個緩衝區嗎？

來看 SQLite 做者的回答：(19) INSERT is really slow - I can only do few dozen INSERTs per second

Actually, SQLite will easily do 50,000 or more INSERT statements per second on an average desktop computer. But it will only do a few dozen transactions per second. Transaction speed is limited by the rotational speed of your disk drive. A transaction normally requires two complete rotations of the disk platter, which on a 7200RPM disk drive limits you to about 60 transactions per second.

Transaction speed is limited by disk drive speed because (by default) SQLite actually waits until the data really is safely stored on the disk surface before the transaction is complete. That way, if you suddenly lose power or if your OS crashes, your data is still safe. For details, read about atomic commit in SQLite..

By default, each INSERT statement is its own transaction. But if you surround multiple INSERT statements with BEGIN...COMMIT then all the inserts are grouped into a single transaction. The time needed to commit the transaction is amortized over all the enclosed insert statements and so the time per insert statement is greatly reduced.

也就是說，咱們能夠經過將多條插入語句用 BEGIN ... COMMIT 的方法包裹起來做爲單獨的事務來提交，效率將會有巨大的提高。

db_save

最終嘗試將 pendingLogEntries 做爲事務執行的方法。會先檢查 pendingLogEntries count 以及 database 是否正在執行事務，來判斷是否須要使用 BEGIN ... COMMIT 。

BOOL saveOnlyTransaction = ![database inTransaction];

if (saveOnlyTransaction) {
    [database beginTransaction];
}

/* INSERT INTO logs & remove pendingLogEntries */ 

if (saveOnlyTransaction) {
    [database commit];

    if ([database hadError]) {
        NSLog(@"%@: Error inserting log entries: code(%d): %@",
                [self class], [database lastErrorCode], [database lastErrorMessage]);
    }
}
複製代碼

能夠看到這裏的事務並不是強制執行的，所以仍是有優化空間的。好比經過串行隊列來保證每次 save 都能在 transaction 中完成。

db_delete 與 db_saveAndDelete 就不展開了。

The End

DDLog 所提供的 Demo 中還有 CoreDataLogger、WebSocketLogger 等自定義 logger 的擴展。好比，經過 WebSocketLogger 咱們能夠將日誌直接輸出到瀏覽器上來時時預覽和校驗日誌或檢查埋點數據等等。

經過這些 Demo 咱們對 DDLog 的需求徹底能夠經過 Logger 的擴展來實現。好比，經過 mmap 來存儲日誌。這方面 Xlog 和 logan 目前就是這麼實現的。而基於微信現有提供的 MMKV，咱們用 Logger 簡單擴展就能實現高效存儲。

DDLog 中能夠看到其對 dispatch source 的安全使用，包括 queue 和 timer 和多線程的處理；對 NSProxy 的巧妙使用來爲 fileHandler 添加 buffer 支持；對系統的 log system 的瞭解，以及代碼的健壯性，日誌更新存儲策略等等。很是值得一看。