第1部分 又一次認識C語言

程序調試的利器—日誌

假設世界上有一個人能夠保證一次寫出來的代碼是百分之百正確的，那麽毫無疑問，他一定是世界上最棒的程序猿，沒有之中的一個。

為什麽要求代碼寫好過後要進行充分的自測(包含單元測試和集成測試)？就由於是人皆會犯錯，是程序就會有bug

一般而言，對代碼的調試有下面幾種方法：

第一，憑肉眼看。在開發階段。我們編寫的每一行代碼都須要用我們的“火眼金睛”多審查幾遍。

假設要問，最好的代碼調試工具是什麽？我覺得是人眼。

無論是代碼還是文檔。在用工具檢查之前，都須要先過了我們眼睛這一關。

第二。對代碼進行編譯，以發現語法錯誤。編譯器能夠幫助我們發現代碼中存在的語法錯誤，但對於那些隱蔽性的錯誤(如邏輯錯誤等)無能為力。

第三，用代碼檢查工具(如Pclint等)來走查代碼。

假設代碼編譯通過。並不表示它就沒有問題了。在學校的時候。我們一般覺得僅僅要程序能夠執行就能夠了。但在實際的軟件開發項目中，程序能夠跑起來，僅僅是“萬裏長征走完了第一步”。

用代碼檢查工具能夠發現許多編譯器無法發現的錯誤，如變量定義了未引用、不同數據類型之間相互賦值、函數未聲明便被調用等。

第四，對代碼進行調試。

對於執行正常而輸出結果不對的程序。我們能夠用設置斷點並進行單步跟蹤調試的方法來發現當中存在的問題。比如，在VC++ 6.0裏面，可實現對代碼的單步調試，並輸出變量在某一步產生的值，可據此推斷程序的邏輯的正確與否。

第五。對程序的日誌文件進行分析。

對代碼的單步調試僅僅在代碼行數較少的時候比較適用，如學校教材上面的程序。但在實際的軟件項目中，代碼少則幾千行。多則數萬行，用單步調試的方法顯然不恰當。為了跟蹤某一變量值的變化，用該方法可能要花費幾個小時，這對工作效率產生了嚴重影響。

為了解決大程序文件代碼調試問題，日誌系統應運而生。

在程序中的重要地方打印日誌，之後對產生的日誌進行分析，可找到相應代碼的問題。

因此，日誌文件分析成了大型軟件項目中代碼調試的主要手段。

本文對日誌相關內容進行具體的說明。

1.什麽是日誌文件？

在業務軟件系統中大量使用日誌。日誌能夠起到“按圖索驥”的作用，它對於故障定位和系統正常執行維護具有舉足輕重的作用。

日誌文件是程序中寫日誌函數產生的記錄程序執行情況的文件。寫日誌函數也是用C語言編寫的。同C函數一樣被調用。在恰當的地方調用該函數，可對整個程序的執行狀況有一個全面的了解，方便對程序的跟蹤調試。

2.有關日誌等級和日誌配置說明

(1)日誌等級

事有輕重緩急，日誌信息也有重要與不重要之分。一般依照重要程度，將日誌等級分為幾類。

在作者參與過的軟件開發項目中。共同擁有7個等級，用宏定義表演示樣例如以下：

//日誌等級定義

#define LOG_FATAL (int)1 //嚴重錯誤

#define LOG_ERROR (int)2 //一般錯誤

#define LOG_WARN (int)3 //警告信息

#define LOG_INFO (int)4 //一般信息

#define LOG_TRACE (int)5 //跟蹤信息

#define LOG_DEBUG (int)6 //調試信息

#define LOG_ALL (int)7 //全部

開發者依據所要打印的日誌的具體情況採用不同的日誌等級。

(2)日誌配置

由於不同產品程序行數、部署情況、實現功能等的區別，對日誌打印的要求也不盡同樣，因此須要有配置來控制日誌的產生數量和顯示情況。

在配置文件裏，有一個專門的[LOG]配置段。當中的配置項例如以下：

[LOG]

;日誌等級, 0-Fatal 1-Error 2-Warn 3-Info 4-Trace 5-Debug 6-All

LogLevel=

;每一個日誌文件的最大容量

LogMaxSize=

;是否輸出該條日誌在代碼中的行數, 1-Yes 0-No

LogPosition=

當中。LogLevel用於控制打印日誌的等級。代碼中日誌等級比配置值大的日誌信息均不在日誌文件裏顯示。LogMaxSize用於控制生成一個日誌文件的大小的上限。超過該值後，便又一次生成文件；LogPosition用於控制是否在日誌文件裏顯示代碼行數。方便將日誌與代碼相應起來。

3.怎樣調用寫日誌函數？

日誌函數的調用遵循一般函數的調用規則。有兩類寫日誌函數。例如以下所看到的：

(1)第一類形如：WriteLog(LogLevel, LogInfo)。當中。參數LogLevel指日誌等級(見第2節中的說明)；參數LogInfo是具體要打印的日誌信息。我們據此信息來檢查程序的執行情況。該函數的調用示比如：WriteLog(LOG_INFO, "The value of this integer is 3.")，日誌等級為LOG_INFO，日誌信息為“The value of this integer is 3.”(該信息會輸出到日誌文件裏)。

(2)第二類形如：WriteLogEx(LogLevel, LogInfo, ParaInfo)。這是擴展的日誌函數，不但能夠輸出日誌信息，還能夠在日誌信息中顯示變量的值。該函數的調用示比如：WriteLogEx(LOG_INFO, "The value of integer iInt is %d.", iInt)，該日誌要輸出整型變量iInt的值，能夠將該函數的調用與printf函數的調用比較起來看(能夠覺得WriteLogEx函數僅僅是在printf函數中添加了一個日誌等級參數)。

4.編寫日誌的基本原則、基本要求和位置要求

日誌編寫的整體原則是簡單清晰、便於排查問題。

(1)日誌編寫的基本原則

1)顯式輸出，關鍵信息必須輸出。

2)在編碼時使用正確的日誌級別，error錯誤和warning錯誤必須反應出實在的含義，不是特別嚴重的問題不能將日誌等級定義為LOG_FATAL；

3)在寫日誌描寫敘述時。要使用正常簡單易懂的語言。不能使用晦澀難懂的語言或某些專業術語。

4)在極少數特殊情況不希望用戶知道時，可使用特殊日誌標記。

5)為了寫出優美的代碼。在自己改動或加入代碼的地方。都要正確的打上標記(包含作者、日期信息等)，方便追蹤版本號的演進情況。

(2)日誌編寫的基本要求

1)分多條信息分別輸出，不要企圖一次將全部打印信息出來；

2)分時輸出。

3)必須分日誌級別。這樣可依據等級迅速對日誌進行分析；

4)控制日誌信息的條數。不重要的信息盡量不要打印日誌。

(3)輸出日誌的位置要求

1)全部的輸入輸出，包含收消息和發消息都要求輸出日誌；

2)關鍵控制點必須輸出日誌；

3)調用底層或第三方軟件。必須輸出日誌。並且對不可靠底層，必須加上begin/end兩行日誌；

4)對方系統處理時間必須輸出日誌，以利以後維護時高速定位性能問題。

此外，作者覺得，在編寫日誌時還須要註意下面幾點：

1) 在編寫日誌時須要註重日誌細節，目標是為了方便以後維護，在遇到問題時，能夠高速定位問題。

2) 不要在同一行中寫意思反復的日誌。

3) 日誌須要足夠的精簡，不要任意換行。

4) 日誌中字段之間能夠用空格或其他符號分斷，不能將日誌一直連續而不將其分斷，盡量使日誌本身具備進行“識文斷句”的能力。

5) 對於日誌中的特殊信息(如會話號、IP地址等)，用特殊的符號進行標識，其主要目的是為了便於搜索。

5.總結

日誌系統在軟件程序中占有很重要的地位，日誌文件是排查程序問題的主要工具，是程序調試的利器。作為一名合格的軟件開發project師。一定要學會日誌函數的靈活調用及準確通過日誌文件來定位程序問題。

“實踐出真知”，僅僅有通過不斷的積累和總結。才會對日誌有更全面的認識。

附：

一起數據庫表唯一索引問題的排查過程

【文章摘要】

某模塊在系統中占有很重要的地位，該模塊能夠對符合條件的動態信箱進行清理。本模塊直接清理的信箱包含：過期動態信箱、冷凍信箱和空動態信箱；刪除非動態信箱由本模塊發送消息到還有一模塊完畢。

近期。某局點出現了信箱刪除緩慢而導致過期動態信箱積壓的問題，經過仔細的分析和追蹤，最後定位的原由於用戶數據表和暫時表在相應字段上的索引不一致。本文對該問題的分析過程進行具體介紹，為相關模塊現場問題的分析提供了故意的參考。

【關鍵詞】

模塊 數據庫 索引 過期動態信箱

一、現場問題描寫敘述

現場外籍返回了本模塊的幾個問題，包含：

(1)某些滿足刪除條件的過期信箱還存在於數據庫中，而沒有被清除掉。

(2)現場有N個數據庫，某個數據庫中的信箱個數是其他數據庫的兩倍。

現場返回了該模塊的日誌，發現模塊執行正常，有刪除過期動態信箱的記錄。

二、本接口刪除的信箱類型

本接口刪除的信箱類型如圖1所看到的：

圖1本模塊刪除的信箱類型

從圖1能夠看出，本模塊要刪除三類信箱：過期動態信箱、冷凍信箱和空動態信箱。

三、本接口程序執行整體流程

本模塊的程序整體流程如圖2所看到的：

圖2程序執行整體流程

從圖2能夠看出，全部滿足刪除條件的信箱是先被掃描出來放到內存鏈表中。最後再執行存儲過程將其清理掉。

四、問題原因初步分析

與現場外籍溝通，讓他返回了本模塊的日誌、該模塊要用到的一些系統參數的值，並讓他完整地導回了現場的數據庫。

經過對參數及數據庫中數據的分析。我們發現：

(1)依據系統參數的值。確實應該有大量的信箱號碼被刪除掉。

(2)某一個數據庫中的數據是其他數據庫的兩倍。

鑒於本模塊執行是正常的。我們覺得問題的解決辦法可能是：

(1)本模塊所調用的存儲過程沒有將全部滿足條件的信箱掃描出來。

(2)全部信箱盡管被掃描出來了。但沒有全然插入本模塊的內存鏈表中。

(3)全部信箱盡管被插入到本模塊的內存鏈表中，但刪除信箱的存儲過程沒有將這些信箱全部刪除掉。

五、問題定位

我們在測試部環境上恢復了現場導回來的數據庫。並在本模塊代碼中加入了部分調試日誌。用以推斷每一步掃描出的信箱和插入到內存表中的信箱的個數。

準備工作完畢之後。我們啟動了本模塊程序。

在經過長時間的執行之後，我們查看了本模塊的日誌，部分關鍵的日誌例如以下：

2014.02.25 17:18:57.647 [INFO ] F[xxx.c ] L[004001] ScanTask0: zzx test(Step 1). Scantable=0, total Scaned num=141, insert into list num=141 //第一步流程處理過期動態信箱

2014.02.25 17:18:57.022 [INFO ] F[xxx.c ] L[004285] ScanTask0: zzx test(Step 2). Scantable=0, total Scaned num=141, insert into list num=141 //第二步流程處理冷凍信箱，數目沒添加說明沒有冷凍信箱

2014.02.25 17:46:20.596 [INFO ] F[xxx.c ] L[004671] ScanTask0: zzx test(Step 3). Scantable=0, total Scaned num=147013, insert into list num=147013 // 第三步流程處理無留言動態信箱，147013-141為無留言動態信箱數目

2014.02.25 17:48:08.123 [INFO ] F[xxx.c ] L[004847] ScanTask0: Finished processing, total mailbox num:147013, processed mailbox num:141 //總的掃描出來的信箱數和刪除掉的信箱數

從日誌能夠看出，僅僅要是掃描出來的信箱，都是全然被插入到內存鏈表中的，也是全然被刪除掉的(無留言動態信箱沒有被刪除。是由於刪除無留言動態信箱的標誌沒有被打開)。

我們發現了一個問題，在第一步處理過期動態信箱流程中，僅僅掃描出來了141個信箱。但實際上在數據庫中存在的過期動態信箱遠不止這個數目。

那麽問題一定出在第一步。這樣就縮小了搜尋範圍。

六、真相大白

依據上一步的分析，是在處理過期動態信箱的流程中出了問題，我們就須要對該流程進行重點的分析。

查詢過期信箱的流程如圖3所看到的：

圖3查詢過期信箱流程

圖3所看到的，該流程涉及到兩個存儲過程：存儲過程1和存儲過程2。當中，存儲過程1用以推斷是否存在過期信箱(該存儲過程的返回值為過期信箱的個數)，存儲過程2用以將過期信箱掃描出來。

通過對第一步的日誌進行更加仔細的分析，發現存儲過程1掃描出的信箱數有十幾萬，但存儲過程2返回的信箱數僅僅有141個。

那麽一定是存儲過程2有問題。

下面該存儲過程進行分析。

(1)該存儲過程將用戶信息從用戶信息表中取出之後。插入到暫時表中，然後從暫時表中選擇相關字段並返回。

(2)我們將該存儲過程中的insert語句拷貝出來單獨執行，發現要報錯，報錯信息為用戶信息表和暫時表在某字段上的索引不一致，不能插入該字段同樣的數據。

(3)我們馬上查看數據庫中這兩類表的定義。發現用戶信息表在boxnumber字段上建立了普通索引。而暫時表在boxnumber字段上建立了唯一索引。假設用戶信息表的boxnumber字段值有反復，那麽就不能插入到暫時表中。難道信箱號碼真的有反復？

(4)對現場返回的數據進行分析。發現確有信箱號碼反復的數據。

難道就是索引不一致造成的嗎？依據分析結果。我們將暫時表在boxnumber字段上的唯一索引改動為普通索引，然後又一次導入數據並啟動本模塊，發現一段時間之後，滿足刪除條件的動態信箱都被刪除掉了。

看來。的確是索引不一致惹的禍。

七、總結

在本次現場問題的排查中，依靠數據庫中的記錄發現問題，而利用日誌來定位了問題。雙管齊下。終於找到了癥結所在。

通過本次問題排查。我們總結出的經驗有下面幾個：

(1)詳盡的日誌有助於問題的定位。為了更清晰地了解問題出如今哪段代碼，我們能夠在程序的關鍵節點加入上一些測試日誌，供分析所用。

(2)對於數據表來說，假設字段內容類似，且要進行從一個表到還有一個表的插入等操作。那麽在相應字段上的索引性質一定要同樣(即不能一個為唯一索引，一個為普通索引)，避免由於索引不一致而導致的數據操作失敗問題。

(3)存儲過程中。在insert、update等語句之後，一定要考慮異常處理，即在這些語句執行失敗之後要拋出異常信息，方便定位問題。

(4)現場數據庫表一定要有人定期查看和維護。並定期閱讀數據庫執行日誌，以發現可能存在的問題。

本文對實際軟件開發項目中某模塊的現場問題的排查過程進行了具體的介紹，為相關模塊程序和數據庫設計及維護提供了參考。

(歡迎訪問南郵BBS：http://bbs.njupt.edu.cn/)
(歡迎訪問重郵BBS：http://bbs.cqupt.edu.cn/nForum/index)

(本系列文章每周更新兩篇，敬請期待！本人新浪微博：http://weibo.com/zhouzxi?topnav=1&wvr=5，微信號：245924426，歡迎關註！

)

讓你提前認識軟件開發(15)：程序調試的利器—日誌