Effective Debug Logging (part 1)
æœ‰æ„ŸäºŽå½“æ—¶åœ¨å¦æ ¡çš„æ—¶å€™åšé¡¹ç›®å’Œè¿›å…¥å…¬å¸ä¹‹åŽå‚与产å“å¼€å‘çš„ç»åŽ†ï¼Œæ·±æ„Ÿäº§å“æ”¯æŒçš„难度——客户的环境åƒå·®ä¸‡åˆ«ï¼Œå› æ¤å¯èƒ½å‡ºçŽ°çš„é—®é¢˜ä¹Ÿåƒå·®ä¸‡åˆ«ï¼Œè€Œä¸”å¾ˆå¤šé—®é¢˜åªæœ‰åœ¨å®¢æˆ·çš„çŽ¯å¢ƒå½“ä¸æ‰å¯èƒ½é‡çŽ°ï¼Œè¿™ä¸ªæ—¶å€™ï¼Œå¦‚ä½•å¿«é€Ÿçš„å®šä½é—®é¢˜å¹¶ç»™å‡ºè§£å†³æ–¹æ¡ˆï¼Œæ˜¯ä¸€ä¸ªéžå¸¸é‡è¦çš„问题。
通常我们采用的都是调试日志,也就是Debug Logging的方法。在æ£å¸¸çš„æƒ…况下,调试日志并ä¸ä¼šè¢«æ‰“å°å‡ºæ¥ï¼Œåªæœ‰å½“出现问题时,通过适当的方å¼ï¼ˆé…置文件或者命令行)将其打开,在客户环境当ä¸é‡çŽ°ï¼Œå¹¶å°†è°ƒè¯•æ—¥å¿—æ”¶é›†åˆ°å¼€å‘者处分æžã€‚å› æ¤ï¼Œå¦‚何有效地在产å“代ç 当䏿·»åŠ è°ƒè¯•æ—¥å¿—ï¼Œæ˜¯å½±å“了软件维护效率的一个é‡è¦å› ç´ ã€‚
è¿™å‡ ç¯‡æ–‡ç« ä¸»è¦å…³æ³¨çš„就是如何有效的写调试日志以便于分æžã€‚å› ä¸ºæˆ‘æ‰€ä»Žäº‹çš„é¡¹ç›®ä¸»è¦ä½¿ç”¨C/C++进行开å‘ï¼Œå› æ¤æ–‡ç« 当ä¸çš„介ç»ä¹Ÿä¸»è¦é›†ä¸åœ¨å¦‚何在C/C++的大型程åºå½“䏿’°å†™è°ƒè¯•日志。
æ–‡ç« ä¸»è¦å…³æ³¨åœ¨ä»¥ä¸‹å‡ 点问题:
- è°ƒè¯•æ—¥å¿—çš„ç›®çš„ï¼šç¡®å®šè°ƒè¯•æ—¥å¿—è®¾è®¡çš„ç›®æ ‡
- 输出调试日志的方å¼ï¼šè°ƒè¯•日志应该输出到哪里
- 调试日志的分级和分类:æé«˜æ—¥å¿—的信噪比
- 如何写调试日志:应该在什么地方写什么
- 如何分æžè°ƒè¯•日志:精力应该放在刀刃上
这是第一部分,我们主è¦å…³æ³¨åœ¨å‰ä¸¤ä¸ªä¸»é¢˜ï¼šè°ƒè¯•日志的目的和输出调试日志的方å¼ã€‚
è°ƒè¯•æ—¥å¿—çš„ç›®çš„å’Œè®¾è®¡ç›®æ ‡
è°ƒè¯•æ—¥å¿—çš„æ ¹æœ¬ç›®çš„æ˜¯ä¸ºäº†å®šä½é”™è¯¯ã€‚在这个目的下,我们æ‰ä¼šè¿›è¡Œæ›´åŠ ç»†è‡´çš„è°ƒè¯•æ—¥å¿—çš„è®¾è®¡ã€‚
说起定ä½é”™è¯¯ï¼Œé¦–先是这ç§è¡Œä¸ºçš„ä¸»ä½“ï¼šè°æ¥å®šä½é”™è¯¯ï¼Ÿé¦–先当然是用户。我们希望,在大多数情况下,用户å¯ä»¥åœ¨å‡ºçŽ°é”™è¯¯æ—¶é€šè¿‡å¯¹äºŽè°ƒè¯•æ—¥å¿—çš„ç®€å•分æžå³å¯å®šä½é”™è¯¯ã€‚ä½†æ˜¯è¿™ç§æ–¹æ³•很容易让人将调试日志的作用高估:程åºå‘˜å¸Œæœ›ç”¨æˆ·ä¼šåŽ»çœ‹è°ƒè¯•æ—¥å¿—ã€‚äº‹å®žä¸Šï¼Œè°ƒè¯•æ—¥å¿—å¯¹äºŽç”¨æˆ·çš„æŽ’é”™å·¥ä½œå¹¶ä¸åº”作为一线工具,至少ä¸åº”è¯¥ç”¨æ¥æŠ¥å‘Šç³»ç»Ÿçš„é”™è¯¯ï¼›å¯¹äºŽç³»ç»Ÿçš„é”™è¯¯ï¼Œä¾‹å¦‚ç”¨æˆ·æ²¡æœ‰ç»™ä¸Žæ£ç¡®çš„输入,或é…置文件解æžé”™è¯¯ï¼Œè¿™ç§éœ€è¦ç”¨æˆ·åŽ»åšä¸€äº›è¡Œä¸ºæ‰èƒ½è®©ç³»ç»Ÿå·¥ä½œèµ·æ¥çš„æ¶ˆæ¯ï¼Œåº”è¯¥ç”¨æ›´åŠ ç›´æŽ¥çš„æ–¹å¼é€šçŸ¥ç”¨æˆ·ã€‚例如在Windows上é¢ï¼Œä½¿ç”¨Windows事件日志(Event Log)就是一ç§å¾ˆå¥½çš„é€‰æ‹©ã€‚ä½†æ˜¯ï¼Œè¿™æ¡æ¶ˆæ¯ä»ç„¶åº”该记录进调试日志,以便å¯ä»¥è®°å½•下错误å‘生的细节以便于程åºå‘˜è¿›è¡Œåˆ†æžã€‚
å¦å¤–一个需è¦åˆ†æžè°ƒè¯•日志æ¥å®šä½é”™è¯¯çš„å°±æ˜¯è½¯ä»¶ç»´æŠ¤äººå‘˜ã€‚å› ä¸ºè½¯ä»¶çš„è§„æ¨¡é—®é¢˜ï¼Œæˆ–è€…ç”±äºŽæµç¨‹çš„ä¸åŒï¼Œä¹Ÿè®¸è½¯ä»¶ç»´æŠ¤äººå‘˜å¹¶ä¸æ˜¯æœ¬æ¥çš„系统开å‘äººå‘˜ï¼Œè€Œæ— è®ºå¦‚ä½•ï¼Œå¯¹äºŽç³»ç»Ÿçš„å·¥ä½œæ–¹å¼ï¼Œè½¯ä»¶ç»´æŠ¤äººå‘˜éƒ½æ¯”ç”¨æˆ·äº†è§£çš„æ›´å¤šã€‚å› æ¤å¦‚果调试日志足够好,他们å¯ä»¥é€šè¿‡è°ƒè¯•日志,结åˆå¯¹äºŽè½¯ä»¶å·¥ä½œæ–¹å¼çš„ç†è§£å‘çŽ°æ›´å¤šçš„é—®é¢˜ï¼Œå¹¶ç»™å‡ºç”¨æˆ·è§£å†³æ–¹æ¡ˆã€‚å› æ¤ï¼Œå°†è°ƒè¯•æ—¥å¿—å†™å¾—æ›´åŠ æ˜“æ‡‚ï¼Œè¯´æ˜Žè½¯ä»¶â€œåšäº†ä»€ä¹ˆï¼Œå‘生了什么结果â€ï¼Œè€Œä¸æ˜¯â€œè°ƒç”¨äº†ä»€ä¹ˆå‡½æ•°ï¼Œè¿”回了什么值â€ï¼Œå°±èƒ½å¤Ÿè®©æ›´åŠ å‰ç«¯çš„è½¯ä»¶ç»´æŠ¤äººå‘˜çš„å¤„ç†æŽ‰æ›´å¤šçš„é—®é¢˜ï¼Œç›¸åº”çš„ï¼Œéœ€è¦å¼€å‘人员亲自解决的问题的数é‡å°±ä¼šå‡å°‘。
最åŽçš„ä¼šåŽ»åˆ†æžæ—¥å¿—的就是软件开å‘äººå‘˜ã€‚å› æ¤ï¼Œæ·»åŠ å¿…è¦çš„å¼€å‘人员ç†è§£çš„ä¿¡æ¯ä¹Ÿæ˜¯å¿…è¦çš„ï¼Œæ¯”å¦‚å‡½æ•°è°ƒç”¨å‚æ•°å’Œè¿”回值的跟踪,æ¡ä»¶åˆ†æ”¯çš„跟踪,出现错误的代ç è¡Œå’Œæºæ–‡ä»¶ç‰ç‰ï¼Œä»¥ä¾¿æŽŒæ¡æœ‰æºä»£ç 的开å‘人员å¯ä»¥å¯¹é”™è¯¯çš„æµç¨‹è¿›è¡Œè·Ÿè¸ªå¹¶é‡çŽ°ã€‚åŒæ—¶ï¼Œç”±äºŽåˆ°äº†å¼€å‘人员手ä¸çš„往往都是éžå¸¸æ£˜æ‰‹çš„问题,往往伴éšçš„大é‡çš„调试日志æ¡ç›®ï¼Œå› æ¤ï¼Œè®©è°ƒè¯•æ—¥å¿—çš„åˆ†æžæ›´å®¹æ˜“自动化对于开å‘人员定ä½é”™è¯¯çš„帮助也是éžå¸¸å¤§çš„。在建立了良好的自动的调试日志分æžå·¥å…·ä¹‹åŽï¼Œå¯¹äºŽå·²çŸ¥çš„问题,就å¯ä»¥é€šè¿‡å·¥å…·è¿›è¡Œå¿«é€Ÿçš„定ä½äº†ã€‚
综上,我们所åšå¾—å¯¹äºŽè°ƒè¯•æ—¥å¿—çš„å·¥ä½œéƒ½æ˜¯ä¸ºäº†èƒ½å¤Ÿæ›´å®¹æ˜“ã€æ›´æ—©çš„定ä½é”™è¯¯ã€‚为了达到这个目的,我们需è¦èƒ½å¤Ÿè®©è°ƒè¯•日志便于查找和æœé›†ï¼Œä¾¿äºŽäººè¯»å–å’Œç†è§£ï¼Œä»¥åŠä¾¿äºŽå·¥å…·è¿›è¡Œè§£æžã€‚
Tip 1:调试日志的设计应该以“便于定ä½é”™è¯¯â€ä¸ºä¸å¿ƒç›®æ ‡
第一个问题就是需è¦è°ƒè¯•日志便于æœé›†ï¼Œä¹Ÿå°±æ˜¯è°ƒè¯•日志的输出问题。
输出调试日志的方å¼
对于调试日志应该输出到哪里,人们有很多ä¸åŒçš„看法,在ä¸åŒçš„环境当ä¸ä¹Ÿå„有优劣。比较æµè¡Œçš„å‡ ç§è§‚点是:
- è¾“å‡ºåˆ°æ ‡å‡†è¾“å‡º(stdout)æˆ–æ ‡å‡†é”™è¯¯(stderr)。这ç§ä¸€èˆ¬å‡ºçŽ°åœ¨äº¤äº’å¼å‘½ä»¤è¡Œå·¥å…·å½“ä¸ï¼Œä½¿ç”¨stdio或iostream当ä¸çš„库函数æ¥ä¹¦å†™ã€‚è¿™ç§ä¹¦å†™æ–¹å¼ç¬¦åˆç¨‹åºå‘˜çš„ä¹ æƒ¯ï¼Œä¾‹å¦‚Unixçš„ä¼ ç»Ÿçš„å·¥å…·é€šå¸¸ä½¿ç”¨-v(如mplayer),-debug(如openssl)æˆ–å…¶ä»–çš„é€‰é¡¹æ¥æŠŠç»†è‡´çš„æ—¥å¿—è¾“å‡ºåˆ°stdoutå’Œstderr。这ç§è¾“出的优势在于便于é‡å®šå‘到文件或管é“。é‡å®šå‘çš„æ–‡ä»¶æ¯”è¾ƒé€‚åˆæœé›†è°ƒè¯•æ—¥å¿—ï¼Œè€Œä½¿ç”¨ç®¡é“æ¯”较适åˆå®žæ—¶åˆ†æžã€‚其劣势也是éžå¸¸æ˜Žæ˜¾çš„ï¼šè¿™ç§æ–¹å¼ä»…适用于交互å¼å‘½ä»¤è¡Œå·¥å…·ï¼Œå¯¹äºŽGUI程åºã€åŽå°å®ˆæŠ¤è¿›ç¨‹æˆ–者æœåŠ¡ç¨‹åºå°±ä¸å¤ªé€‚åˆäº†ã€‚当然对于Windows GUI程åºï¼Œæœ‰ä¸€ç§æ–¹å¼å¯ä»¥ä½¿ç”¨CRT Output Routing,但是并ä¸é€šç”¨ï¼Œè€Œä¸”ä¼šå¤±åŽ»ä½¿ç”¨è¿™ç§æ–¹å¼çš„æ ¹æœ¬ä¼˜åŠ¿ï¼Œå³çµæ´»çš„é‡å®šå‘。
- 输出到System Debug Buffer。å³é€šè¿‡OutputDebugStringW/Aå‡½æ•°ï¼Œæˆ–è€…å†…æ ¸æ€çš„DbgPrint(Ex)å‡½æ•°ã€‚è¿™ç§æ–¹å¼å¹¶ä¸è§å¾—有多少优势,尤其是必须通过调试器或其他工具æ‰å¯ä»¥çœ‹åˆ°æˆ–dump到文件,给在用户处æœé›†ä¿¡æ¯é€ æˆäº†å¾ˆå¤§çš„麻烦。在我看æ¥ï¼Œä½¿ç”¨è¿™ç§æ–¹å¼å¾ˆå¤šæ—¶å€™è¿˜æ˜¯ä¸å¾—å·²è€Œä¸ºä¹‹ï¼Œä¾‹å¦‚åœ¨å†…æ ¸æ€é™¤äº†DbgPrint(Ex)ï¼Œä¼¼ä¹Žæ²¡æœ‰åˆ«çš„é€‰æ‹©ã€‚ä½†æ˜¯ä½¿ç”¨è°ƒè¯•å™¨æ¥æœé›†ä¸€äº›ä¿¡æ¯è¿˜æ˜¯ä¸€ç§å¯ä»¥é€‰æ‹©çš„æ–¹æ¡ˆï¼Œä¾‹å¦‚对于Windows API调用的记录,skywing在他的blogä¸Šé¢æä¾›äº†ä¸€ç§åœ¨WinDbg当ä¸å¯ç”¨çš„æ–¹æ³•,但是ä»ç„¶å¦‚我所说,在实际的用户那里,并没有太大的æ„义。
- è¾“å‡ºåˆ°æ—¥å¿—æ–‡ä»¶ã€‚è¿™ç§æ˜¯ä½¿ç”¨çš„æœ€å¤šçš„æ–¹æ¡ˆã€‚è¿™ç§æ–¹å¼å¯ä»¥é€‚用于除了交互å¼å‘½ä»¤è¡Œå·¥å…·ä¹‹å¤–的所有组件,而且éžå¸¸é€‚åˆç”¨æ¥ä»Žç”¨æˆ·å‡ºçŽ°é—®é¢˜çš„çŽ¯å¢ƒå½“ä¸ç›´æŽ¥æ”¶é›†ï¼Œå¹¶ç”±ç¨‹åºå‘˜è¿›è¡Œåˆ†æžã€‚ä½†æ˜¯è¿™ç§æ–¹æ¡ˆå¯èƒ½å˜åœ¨ä¸€äº›ç»†èŠ‚é—®é¢˜éœ€è¦è€ƒè™‘,例如将日志文件写在哪里(临时文件目录,专用的调试日志目录,或者其他地方),文件如何命å和切分,如果调试日志é‡è¿‡å¤§å¦‚何处ç†ï¼Œå†™è°ƒè¯•日志时出现错误怎么办ç‰ç‰ã€‚è¿™å‡ ä¸ªé—®é¢˜æ²¡æœ‰å›ºå®šçš„ç”æ¡ˆï¼Œå…³é”®åœ¨äºŽä¸€æ—¦ç¡®å®šä¸‹æ¥ï¼Œå°±éœ€è¦åœ¨æ•´ä¸ªè½¯ä»¶å½“ä¸ä¿æŒä¸€è‡´ã€‚在我现在从事的项目ä¸ï¼Œæˆ‘们使用的是写入到专用的调试日志目录当ä¸ï¼ŒåŒæ—¶è¿™ä¸ªç›®å½•å¯ä»¥ç”±ç”¨æˆ·é€šè¿‡é…置文件修改;文件å使用basename.yyyymmdd.####çš„æ ¼å¼ï¼Œyyyymmdd是用户本地时间的年月日,####是从1开始的编å·ã€‚æ¯ä¸ªæ–‡ä»¶å¤§å°ä¸è¶…过æŸä¸ªå€¼ï¼Œä¸€æ—¦è¶…过就å¦å¼€ä¸€ä¸ªæ–‡ä»¶ã€‚è¿™ç§ç»“构便于辅助工具寻找和收集调试日志并打包,以åŠåœ¨è°ƒè¯•日志过多的时候由一个守护程åºè¿›è¡Œæ¸…ç†ã€‚å¯¹äºŽå†™å…¥æ—¥å¿—çš„é”™è¯¯ï¼Œå»ºè®®æ ¹æ®å½“å‰çš„æ—¥å¿—级别æ¥å¤„ç†ï¼Œå¦‚æžœéœ€è¦æ‰“出的本身就是一个严é‡é”™è¯¯çš„æ—¥å¿—,最好使用æŸç§ä¸å¤ªå®¹æ˜“失败的方å¼å°†æ—¥å¿—å†™å…¥å…¶ä»–åœ°æ–¹ï¼Œä¾‹å¦‚ç³»ç»Ÿäº‹ä»¶æ—¥å¿—ï¼›è€Œå¦‚æžœå†™å…¥çš„åªæ˜¯ä¸€äº›ä¿¡æ¯æ€§çš„æˆ–者调试
性的消æ¯ï¼Œåˆ™å¯ä»¥é€‰æ‹©å¿½ç•¥ã€‚
Tip 2:选用åˆé€‚的日志输出方å¼ï¼Œä»¥ä¾¿äºŽæ”¶é›†å’Œå¤„ç†ä¸ºç›®æ ‡è®¾è®¡ã€‚用久ç»è€ƒéªŒçš„æ–¹æ¡ˆï¼Œè¾“出到stdout/stderræˆ–å…·æœ‰ç»Ÿä¸€æ–‡ä»¶åæ ¼å¼çš„æ—¥å¿—文件。
如果没有特殊的需求,对于交互å¼å‘½ä»¤è¡Œå·¥å…·ä½¿ç”¨ç›´æŽ¥è¾“出到stdout/stderr,对于其他直接输出到日志文件,是调试日志输出的首选。我们当å‰ä½¿ç”¨çš„æ–‡ä»¶ç»„织方å¼ä¹Ÿå¯ä»¥å€Ÿé‰´ã€‚æŽ¥ä¸‹æ¥æˆ‘们就开始谈论如何能够有效的书写调试日志的内容。