DDLog原始碼解析二:設計初衷

weixin_34075551發表於2017-12-04

導語:

DDLog,即CocoaLumberjack是iOS開發用的最多的日誌框架,出自大神Robbie Hanson之手(還有諸多知名開源框架如 XMPPFrameworkCocoaAsyncSocket,都是即時通訊領域很基礎應用很多的框架)。瞭解DDLog的原始碼將有助於我們更好的輸出程式碼中的日誌資訊,便於定位問題,也能對我們在書寫自己的日誌框架或者其他模組時有所啟發。

此係列文章將分為以下幾篇:
- DDLog原始碼解析一:框架結構
- DDLog原始碼解析二:設計初衷
- DDLog原始碼解析三:FileLogger

上一節介紹了框架結構和主要幾個類的內容,本節將重點關注DDLog的核心部分,對於執行緒的考慮:通過一些執行緒方面的設計,以達到上一節跳提到的“準確”、“快速”、“安全”的目的,試圖去解析DDLog設計的初衷,下面我將通過逐步引導來切入正題:

如何快速?

  1. 作為執行緒方面考慮的最基本原則,我們都應該想到日誌作為高頻操作,由於不需要UIKit方面介面呼叫,一定要放在子執行緒。
  2. 另外,“快速”也相對於NSLog,上一節提到NSLog因為要同時輸出日誌兩個源(ASL和控制檯,但不支援檔案),所以效率肯定低,我們平時的需求除非正好跟NSLog輸出的兩個源吻合,否則我們只需要自己對應一個源的輸出,例如只輸出到控制檯。
  3. 程式碼執行的速度,這裡講在後面具體講解DDLog哪些操作可以加速程式碼的執行。

如何準確?

  1. 因為要保證日誌記錄的順序嚴格準確的,我們自然而然地就會想到序列佇列,讓所有想保證順序的操作都在這個佇列中排隊進行。
  2. 當我們要處理多個輸出源的時候,我們肯定要將不同的輸出源的日誌操作放在不同執行緒中,因為不同的源記錄的內容是各自順序正確即可,互相沒有依賴和耦合,如果放在一個執行緒將降低寫日誌的速度。
  3. 另外每個源的記錄內容要高度統一,不然會造成誤解或內容確實,影響問題的定位,這時我們就要保證各個不同源的執行緒要同步,不能某個快很多,其他慢很多,這時候就需要考慮同步的策略,待選的方案可能有@synchronized、NSLock、dispatch_semaphore、NSCondition、OSSpinLock等多種,我們直接站在巨人的肩膀上,dispatch_semaphore是效率最高的。

如何安全?

(1)執行緒安全
DDLog線上程安全方面主要就是通過序列佇列來對一些可能多出訪問的資源進行保護,並且通過dispatch_group和訊號量dispatch_semaphore來保證多個執行緒(序列佇列)中間的同步。
(2)檔案安全
在檔案安全方面,主要就是不能讓日誌檔案無限制的增大,影響到整個app甚至系統的使用,直接影響使用者對app的留存。這裡DDLog有一套時間輪詢和檔案變化時的檢查來控制檔案,並且週期更新檔案的個數,保證總佔用空間及檔案個數符合開發者的配置。

總結

基於以上分析,我們基本摸清了DDLog類線上程方面的設計的考慮,下面考慮一下實際可能需要面對的一個簡單場景:在我們記錄日誌的過程中可能存在先removeLogger、addLogger,然後進行高頻的日誌寫操作,由於addLogger之後支援三種Logger的寫日誌操作,所以需要支援三種Logger一起執行,並且在日誌寫之後又addLogger。

對於上面的場景,我們將DDlog處理時執行緒的設計描繪如下圖:


2204252-5045b300aa265fa6.png
執行緒設計.png
全域性日誌佇列

圖中橙色箭頭表示DDLog類中生成的序列佇列,我們稱之為全域性日誌佇列,用於控制全域性的logger的增減、logger的獲取、各個logger的寫日誌等操作的排序執行,這裡為什麼Logger的增減也要跟寫日誌放在一個佇列中呢? 看下如下的常見DDLog呼叫程式碼:

// 初始化
DDLog addLogger:[DDTTYLogger sharedInstance]];
DDLog addLogger:[[DDFileLogger alloc] init]];

// 開始列印日誌
DDLogInfo(@"log msg 1");
DDLogInfo(@"log msg 2”);
// 更改日誌格式後再列印
[logger setFormatter:myFormatter];
DDLogInfo(@"log msg 3");

當addLogger的兩句程式碼和DDLogInfo在不同執行緒執行時,勢必可能存在一種可能,當第一句DDLogInfo執行時,並沒有將日誌寫到檔案中,這就可能是因為沒有按照語句的順序來執行實際的操作。

對於這個佇列主要涉及建立、標記、和判斷當前是否是這個執行緒三個方面:

+ (void)initialize
 {
    static dispatch_once_t DDLogOnceToken;
    
    dispatch_once(&DDLogOnceToken, ^{
        NSLogDebug(@"DDLog: Using grand central dispatch");
        
        _loggingQueue = dispatch_queue_create("cocoa.lumberjack", NULL);
        _loggingGroup = dispatch_group_create();
        
        void *nonNullValue = GlobalLoggingQueueIdentityKey; // Whatever, just not null
        dispatch_queue_set_specific(_loggingQueue, GlobalLoggingQueueIdentityKey, nonNullValue, NULL);
        
        _queueSemaphore = dispatch_semaphore_create(DDLOG_MAX_QUEUE_SIZE);
        
        // Figure out how many processors are available.
        // This may be used later for an optimization on uniprocessor machines.
        
        _numProcessors = MAX([NSProcessInfo processInfo].processorCount, (NSUInteger) 1);
        
        NSLogDebug(@"DDLog: numProcessors = %@", @(_numProcessors));
    });
}

這裡注意下,_loggingQueue、_loggingGroup、_queueSemaphore由於在DDLog的類方法和例項方法都要用到,所以需要宣告為靜態變數,並且在DDLog這個類第一次使用時就初始化完成,所以這裡將初始化的過程放在 + (void)initialize 方法中。

各個Logger的序列佇列-- “行進有序”

前面已經提過,由於各個Logger不耦合無依賴關係,所以各個Logger講生成各自的序列佇列來進行內部的寫日誌、設定formatter、flush的順序執行,這裡設定formatter由於是各個Logger通用的程式碼,將其放在基類來執行:

//   @implementation DDAbstractLogger

- (id <DDLogFormatter>)logFormatter 
{
    NSAssert(![self isOnGlobalLoggingQueue], @"Core architecture requirement failure");
    NSAssert(![self isOnInternalLoggerQueue], @"MUST access ivar directly, NOT via self.* syntax.");

    dispatch_queue_t globalLoggingQueue = [DDLog loggingQueue];

    __block id <DDLogFormatter> result;

    dispatch_sync(globalLoggingQueue, ^{
        dispatch_sync(_loggerQueue, ^{
            result = _logFormatter;
        });
    });

    return result;
}

- (void)setLogFormatter:(id <DDLogFormatter>)logFormatter {
    NSAssert(![self isOnGlobalLoggingQueue], @"Core architecture requirement failure");
    NSAssert(![self isOnInternalLoggerQueue], @"MUST access ivar directly, NOT via self.* syntax.");

    dispatch_block_t block = ^{
        @autoreleasepool {
            if (_logFormatter != logFormatter) {
                if ([_logFormatter respondsToSelector:@selector(willRemoveFromLogger:)]) {
                    [_logFormatter willRemoveFromLogger:self];
                }

                _logFormatter = logFormatter;
 
                if ([_logFormatter respondsToSelector:@selector(didAddToLogger:inQueue:)]) {
                    [_logFormatter didAddToLogger:self inQueue:_loggerQueue];
                } else if ([_logFormatter respondsToSelector:@selector(didAddToLogger:)]) {
                    [_logFormatter didAddToLogger:self];
                }
            }
        }
    };

    dispatch_queue_t globalLoggingQueue = [DDLog loggingQueue];

    dispatch_async(globalLoggingQueue, ^{
        dispatch_async(_loggerQueue, block);
    });
}

這段程式碼已經很清楚表明上面圖示的意思:各個Logger內部的寫日誌、設定formatter、flush都將首先被加到全域性日誌佇列中排隊,然後再加到各個Logger內部的日誌序列佇列排隊,通過這兩個序列佇列來保證順序的正確性。
通過全域性日誌佇列和logger內部佇列 兩個佇列的約束,從而保證了日誌相關操作真正做到了“行進有序”。

dispatch_group + dispatch_semaphore:“齊頭並進” + “流量控制”

單個Logger內部通過序列佇列已經保證了日誌相關操作的順序,但我們面臨上面提到的問題----很容易忽略的問題:當我們app的程式被殺掉時,很有可能出現系統日誌或者檔案中的日誌並不如控制檯上完備,丟失了最後時刻的很多重要資訊。 這個原因就是因為系統日誌和寫檔案的序列佇列執行速度比控制檯慢很多,如果程式被殺掉前一時刻有很多日誌操作,就會導致系統日誌和檔案的佇列中有大量排隊中未執行的日誌操作,在殺掉程式時沒法完全flush到對應的源中。

DDLog處理這個情況就是通過dispatch_group + dispatch_semaphore這對GCD基友組合,請留意圖中的綠色箭頭和灰色框內部的部分:

  1. 每個綠色箭頭內部有三個箭頭表示三種輸出源,由於處理日誌速度不同,三個藍色箭頭長度不同,所以綠色箭頭代表的dispatch_group就是要控制三者可以並行執行的前提下,一同向前,等三者都執行完了,才執行後面的日誌語句。
  2. 灰色框體內有多個排隊中待執行的log語句(綠色箭頭),為了控制待執行的語句數量不會無限制的大,這裡使用了訊號量來控制總數量,否則佇列過大就有可能在程式殺掉時,無法全部執行完佇列中待執行的log語句。

通過一段程式碼來了解下:

for (DDLoggerNode *loggerNode in self._loggers)
 {
            // skip the loggers that shouldn't write this message based on the log level

            if (!(logMessage->_flag & loggerNode->_level)) {
                continue;
            }
            
            dispatch_group_async(_loggingGroup, loggerNode->_loggerQueue, ^{ @autoreleasepool {
                [loggerNode->_logger logMessage:logMessage];
            } });
  }
 
dispatch_group_wait(_loggingGroup, DISPATCH_TIME_FOREVER);

dispatch_semaphore_signal(_queueSemaphore);

其中DDLoggerNode就是含有Logger資訊的model,_loggingGroup就是dispatch_group,loggerNode->_loggerQueue就是logger內部的日誌佇列。
可見,對於一次logMessage:logMessage語句,都會將其放在每個logger內部的佇列中去執行,並且通過dispatch_group_wait來保證這個佇列都完成再向後執行,這裡就保證了“齊頭並進”。

上面程式碼中還出現了dispatch_semaphore_signal,它和dispatch_semaphore_wait是好基友,二者通過對初始化時的訊號量分別進行-1和+1操作來保證“流量控制”

_queueSemaphore = dispatch_semaphore_create(1000);

.
.
.

- (void)queueLogMessage:(DDLogMessage *)logMessage asynchronously:(BOOL)asyncFlag 
{
    dispatch_semaphore_wait(_queueSemaphore, DISPATCH_TIME_FOREVER);

    dispatch_block_t logBlock = ^{
        @autoreleasepool {
            [self lt_log:logMessage];
        }
    };

    if (asyncFlag) {
        dispatch_async(_loggingQueue, logBlock);
    } else {
        dispatch_sync(_loggingQueue, logBlock);
    }
}

綜上,總結下DDLogInfo這句日誌語句最終執行程式碼的呼叫棧:
DDLogInfo
V
V
巨集替換
V
V
[DDLog log:]
V
V
[DDLog queueLogMessage:]
V
V
lt_log
V
V
[loggerNode->_logger logMessage:]

巨集替換

這裡的巨集替換,一方面讓程式碼更簡潔,減少程式碼正文中頻繁的介面呼叫和巢狀,另一方面的考慮就是前文提到的“快速”,下面我們從巨集替換實際工作的過程,看下為什麼通過巨集替換可以“快速” (DDLegacyMacros.h):

從DDLogInfo的定義開始:

#define DDLogInfo(frmt, ...)    LOG_OBJC_MAYBE(LOG_ASYNC_INFO,    LOG_LEVEL_DEF, LOG_FLAG_INFO,    0, frmt, ##__VA_ARGS__)

其中使用可變引數... 通過後面的VA_ARGS來標識,VA_ARGS前面的##是為了相容這個位置可能沒有引數的情況。LOG_OBJC_MAYBE定義如下:

#define LOG_OBJC_MAYBE(async, lvl, flg, ctx, frmt, ...) \
        LOG_MAYBE(async, lvl, flg, ctx, __PRETTY_FUNCTION__, frmt, ## __VA_ARGS__)

可以看出LOG_OBJC_MAYBE的巨集定義中只是插入另一個____PRETTY_FUNCTION__(函式名)引數到LOG_MAYBE中,而LOG_MAYBE的定義如下:

#define LOG_MAYBE(async, lvl, flg, ctx, fnct, frmt, ...)                       \
        do { if(lvl & flg) LOG_MACRO(async, lvl, flg, ctx, nil, fnct, frmt, ##__VA_ARGS__); } while(0)

使用do{...}while(0)構造後的巨集定義不會受到大括號、分號等的影響,使{}內部的語句按正常意願執行。這裡其實引數未變,只是替換成LOG_MACRO:

#define LOG_MACRO(isAsynchronous, lvl, flg, ctx, atag, fnct, frmt, ...) \
        [DDLog log : isAsynchronous                                     \
             level : lvl                                                \
              flag : flg                                                \
           context : ctx                                                \
              file : __FILE__                                           \
          function : fnct                                               \
              line : __LINE__                                           \
               tag : atag                                               \
            format : (frmt), ## __VA_ARGS__]

這一步就已經到了類DDLog的log介面中。其中FILE表示檔名,LINE 表示行數。

綜上,上面只是列印函式的巨集定義介面之一DDLogInfo的巨集替換過程,其他幾個巨集定義介面DDLogError、DDLogWarn、DDLogDebug、DDLogVerbose都有著相似的過程,但部分傳入引數有區別,試想下我們如果不要上面的巨集替換,直接讓開發者呼叫[DDLog log : xxxxxx]方法,那開發者一定崩潰了,引數太多了。

所以從易用性角度出發,必然要給開發者暴露只含有必要引數的介面。但是如果DDLogError、DDLogWarn、DDLogDebug、DDLogVerbose、DDLogInfo都分別封裝一個介面,都需要DDLog類中多寫幾次函式的呼叫才能最終呼叫到[DDLog log : xxxxxx]方法,這種方式相對於當前巨集替換的方案明顯增加了很多次堆疊控制元件的申請、儲存返回地址,將形參壓棧,釋放堆疊等操作,必然降低程式碼執行的效率,所以我們說這種巨集替換的方式在預編譯階段就直接將需要使用的最終介面確定,使程式碼執行做到了“快速”,這一點點的提升對於高頻的寫日誌操作來說是有必要的。

相關文章