第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.總結
日志系統在軟體程式中占有非常重要的地位，日志檔案是排查程式問題的主要工具，是程式調試的利器。作為一名合格的軟體開發工程師，一定要學會日志函數的靈活調用及準确通過日志檔案來定位程式問題。
“實踐出真知”，隻有通過不斷的積累和總結，才會對日志有更全面的認識。
附：
一起資料庫表唯一索引問題的排查過程
【文章摘要】
某子產品在系統中占有非常重要的地位，該子產品能夠對符合條件的動态信箱進行清理。本子產品直接清理的信箱包括：過期動态信箱、冷凍信箱和空動态信箱；删除非動态信箱由本子產品發送消息到另一子產品完成。
最近，某局點出現了信箱删除緩慢而導緻過期動态信箱積壓的問題，經過細緻的分析和追蹤，最後定位的原因為使用者資料表和臨時表在對應字段上的索引不一緻。本文對該問題的分析過程進行詳細介紹，為相關子產品現場問題的分析提供了有益的參考。
【關鍵詞】
子產品 資料庫 索引 過期動态信箱
一、現場問題描述
現場外籍傳回了本子產品的幾個問題，包括：
(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)現場資料庫表一定要有人定期檢視和維護，并定期閱讀資料庫執行日志，以發現可能存在的問題。
本文對實際軟體開發項目中某子產品的現場問題的排查過程進行了詳細的介紹，為相關子產品程式和資料庫設計及維護提供了參考。