再見了NSLog

本文原文發表自個人【自建博客】，cnblogs同步發表，格式未經調整，內容以原博客爲準

 

我是前言

打Log是咱們debug時最簡單樸素的方法，NSLog對於objc開發就像printf對於c同樣重要。但在使用NSLog打印大量Log，尤爲是在遊戲開發時（如每一幀都打印數據），NSLog會明顯的拖慢程序的運行速度（遊戲幀速嚴重下滑）。本文探究了一下NSLog如此之慢的緣由，嘗試使用lldb斷點調試器解決DebugLog問題。

---

小測試

測試下分別使用NSLog和printf打印10000次耗費的時間。CFAbsoluteTimeGetCurrent()函數能夠打印出當前的時間戳，精度仍是很高的，因而乎測試代碼以下：

1 2 3 4 5 6 7 8 9 10 11 12 13

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);

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

1 2 3

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的文檔，第一句話就說：Logs an error message to the Apple System Log facility.，因此首先，NSLog就不是設計做爲普通的debug log的，而是error log；其次，NSLog也並不是是printf的簡單封裝，而是Apple System Log(後面簡稱ASL)的封裝。

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每次會將當前的系統時間，進程和線程信息等做爲前綴也打印出來，如：

1	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時不用log。

---

使用斷點+lldb調試器替代Debug Log

關於強大的lldb調試器用一個專題來說都是應該，如今只瞭解一些皮毛，不過就算皮毛的功能也能夠替代NSLog這種方法進行調試了，重要的一點是:使用斷點log不須要從新編譯工程，何況和Xcode已經結合的很好，在此先只說打Log這件事。

簡單斷點+po(p)

斷點時能夠在xcode的lldb調試區使用po或p命令打印對象或變量，對於當前棧幀中引用到的變量都是可見的，因此說假如只是看一眼某個對象運行到這兒是否是存在，是什麼值的話，設個斷點就夠了，何況IDE已經把這個功能集成，鼠標放變量上就能夠了。

lldb一些經常使用調試技巧能夠這篇入門教程

Condition和Action斷點

斷點不止能把程序斷住，觸發時也按必定條件，並且能夠執行（一個或多個）Action，在斷點上右鍵選擇Edit Breakpoint，彈出的斷點設置中能夠添加一些Action：

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

1 2 3 4

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

設置斷點後編輯斷點：

輸入框下面就有支持的格式，表達式(或變量)可使用@exp@這種格式包起來。因而乎輸出：

1 2 3

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