本文原文發表自我的【自建博客】,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有這樣的消耗問題,那該怎么辦呢?
- 拒絕殘留的Log。現在項目都是多人共同開發,我們應該只把Log作為錯誤日志或者重要信息的日志使用,commit前請把自己調試的log去掉(尤其是在循環里寫log的小伙伴,簡直不能一起快樂的玩耍了)
- release版本中消除Log。debug歸debug,再慢也不能波及到release版本,用預編譯宏過濾下就好。
- 是時候換個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