我是前言

打Log是我們debug時最簡單樸素的方法，NSLog對於objc開發就像printf對於c一樣重要。但在使用NSLog列印大量Log，尤其是在遊戲開發時（如每一幀都列印資料），NSLog會明顯的拖慢程式的執行速度（遊戲幀速嚴重下滑）。本文探究了一下NSLog如此之慢的原因，並嘗試使用lldb斷點偵錯程式替代NSLog進行debug log。

小測試

測試下分別使用NSLog和printf列印10000次耗費的時間。CFAbsoluteTimeGetCurrent()函式可以打印出當前的時間戳，精度還是很高的，於是乎測試程式碼如下：

CFAbsoluteTime startNSLog = CFAbsoluteTimeGetCurrent();
for (int i = 0; i < 10000; i++) {
    NSLog(@"%d", i);
}
CFAbsoluteTime endNSLog = CFAbsoluteTimeGetCurrent();

CFAbsoluteTime startPrintf = CFAbsoluteTimeGetCurrent();
for (int i = 0; i < 10000; i++) {
    printf("%d\n", i);
}
CFAbsoluteTime endPrintf = CFAbsoluteTimeGetCurrent();

NSLog(@"NSLog time: %lf, printf time: %lf", endNSLog - startNSLog, endPrintf - startPrintf);

這個時間和機器肯定有關係，只看它們的差別就好。為了全面性，嘗試了三種平臺：

NSLog time: 4.985445, printf time: 0.084193 // mac
NSLog time: 5.562460, printf time: 0.019408 // 模擬器
NSLog time: 10.471490, printf time: 0.090503 // 真機除錯(iphone5)

可以發現，在mac上（模擬器其實也算是mac吧）速度差別達到了60倍左右，而真機除錯甚至達到了離譜的100多倍。

探究原因

基本上這種事情一定可以在Apple文件中找到，看NSLog

ASL

ASL是個啥？從官方手冊上，或者從終端執行man 3 asl都可以看到說明：

These routines provide an interface to the Apple System Log facility. They are intended to be a
replacement for the syslog(3) API, which will continue to be supported for backwards compatibility.

大概就是個系統級別的log工具吧，syslog的替代版，提供了一系列強大的log功能。不過一般我們接觸不到，NSLog就對它提供了高層次的封裝，如這篇文件所提到的：

You can use two interfaces in OS X to log messages: ASL and Syslog. You can also use a number of higher-level approaches such as NSLog. However, because most daemons are not linked against Foundation or the Application Kit, the low-level APIs are often more appropriate

一些底層相關的守護程序(deamons)不會link如Foundation等高層框架，所以asl用在這兒正合適；而對於應用層的用NSLog。

在CocoaLumberjack的文件中也說了NSLog效率低下的問題：

NSLog does 2 things:

• It writes log messages to the Apple System Logging (asl) facility. This allows log messages to show up in Console.app.
• It also checks to see if the application’s stderr stream is going to a terminal (such as when the application is being run via Xcode). If so it writes the log message to stderr (so that it shows up in the Xcode console).

To send a log message to the ASL facility, you basically open a client connection to the ASL daemon and send the message. BUT - each thread must use a separate client connection. So, to be thread safe, every time NSLog is called it opens a new asl client connection, sends the message, and then closes the connection.

意識大概是說，NSLog會向ASL寫log，同時向Terminal寫log，而且同時會出現在Console.app中（Mac自帶軟體，用NSLog打出的log在其中全部可見）；不僅如此，每一次NSLog都會新建一個ASL client並向ASL守護程序發起連線，log之後再關閉連線。所以說，當這個過程出現N次時，消耗大量資源導致程式變慢也就不奇怪了。

時間和程序資訊

主要原因已經找到，還有個值得注意的問題是NSLog每次會將當前的系統時間，程序和執行緒資訊等作為字首也打印出來，如：

2012-34-56 12:34:56.789 XXXXXXXX[36818:303] xxxxxx

當然這些也可能是作為ASL的引數建立的，但不論如何，一定是有消耗的（雖然這個prefix十有八九不是我們需要的看到的）

如何是好

NSLog有這樣的消耗問題，那該怎麼辦呢？

1. 拒絕殘留的Log。現在專案都是多人共同開發，我們應該只把Log作為錯誤日誌或者重要資訊的日誌使用，commit前請把自己除錯的log去掉（尤其是在迴圈裡寫log的小夥伴，簡直不能一起快樂的玩耍了）
2. release版本中消除Log。debug歸debug，再慢也不能波及到release版本，用預編譯巨集過濾下就好。
3. 是時候換個Log系統了，如CocoaLumberjack，自建一個簡單的當然也挺好（其實為了專案需要自己也寫了個小log系統，實現可以按名字和級別顯示log和一些擴充套件功能，以後有機會分享下）

不過個人認為debug時最好還是用偵錯程式進行除錯（尤其是隻需要知道某個變數值的時候）

嘗試使用斷點+lldb偵錯程式打Log

關於強大的lldb偵錯程式用一個專題來講都是應該，現在只瞭解一些皮毛，不過就算皮毛的功能也可以替代NSLog這種方法進行除錯了，重要的一點是:使用斷點log不需要重新編譯工程，況且和Xcode已經結合的很好，在此先只說打Log這件事。

簡單斷點+po(p)

斷點時可以在xcode的lldb除錯區使用po或p命令列印物件或變數，對於當前棧幀中引用到的變數都是可見的，所以說假如只是看一眼某個物件執行到這兒是不是存在，是什麼值的話，設個斷點就夠了，況且IDE已經把這個功能整合，滑鼠放變數上就可以了。

lldb一些常用除錯技巧可以這篇入門教程

Condition和Action斷點

斷點不止能把程式斷住，觸發時也按一定條件，而且可以執行（一個或多個）Action，在斷點上右鍵選擇Edit Breakpoint，彈出的斷點設定中可以新增一些Action：

其中專門有一項就是Log Message，做個小測試：

for (int i = 0; i < 10; i++) {
    // break point here
}

設定斷點後編輯斷點：

輸入框下面就有支援的格式，表示式(或變數)可以使用@[email protected]這種格式包起來。於是乎輸出：

break at: 'main()',  count: 4, sunnyxx says : 3
break at: 'main()',  count: 5, sunnyxx says : 4
break at: 'main()',  count: 6, sunnyxx says : 5

正如所料。
更多的除錯技巧還需要深入研究，不過可以肯定的是，比起單純的使用NSLog，使用好的工具可以讓我們debug的效率更高

總結

• NSLog耗費比較大的資源
• NSLog被設計為error log，是ASL的高層封裝
• 在專案中避擴音交commit自己的Debug log，release版本更要注意去除NSLog，可以使用自建的log系統或好用的log系統來替代NSLog
• debug不應只侷限於log滿天飛，lldb斷點除錯是一個優秀的debug方法，需要再深入研究下

References

https://developer.apple.com/library/mac/documentation/Darwin/Reference/ManPages/man3/asl.3.html
http://theonlylars.com/blog/2012/07/03/ditching-nslog-advanced-ios-logging-part-1/
https://github.com/CocoaLumberjack/CocoaLumberjack/wiki/Performance
https://developer.apple.com/library/mac/documentation/MacOSX/Conceptual/BPSystemStartup/Chapters/LoggingErrorsAndWarnings.html#//apple_ref/doc/uid/10000172i-SW8-SW1
http://www.cimgf.com/2012/12/13/xcode-lldb-tutorial/

原創文章，轉載請註明源地址，blog.sunnyxx.com