浅析 - 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 的了解，以及代码的健壮性，日志更新存储策略等等。很是值得一看。