嵌入式?jīng)]仿真器真的就是只能打log了

來源：https://zhuanlan.zhihu.com/p/24785018?from_voters_page=true

本文適用范圍：Linux系統(tǒng)
使用語言：C/C++
打log的原則
1、異常分支或錯誤處理一定要打log
2、重大操作時一定要打log，下面打log場景會講述
log格式的原則
1、時間戳必須有,最好能夠精確到微秒。精確到秒的時間戳，相信很多人都熟悉，這能夠確認問題的時間和系統(tǒng)uptime的對比，能夠進一步還原問題的場景。
至于到微秒，在多線程程序下，如果進程停止響應(yīng)，可以從日志時間看是否死鎖。
一般格式：
[2017－01－09 12：16：30.541]
2、打log位置的文件名和代碼行數(shù)。這個不用說，用于定位問題根源。其實最重要是防止扯皮。因為程序員大多喜歡copy-paste，如果你不加文件名和行數(shù)，某程序員copy了你的代碼，修改了點，出錯了，到時候把你拉下水。
一般格式：
[2017－01－09 12：16：30.541][network.c:541]
3、有進程id。有些log機制在進程重啟時，不會重新生成一個日志文件，而是直接在同一個日志文件后面添加日志?；蛘?，有時候同一程序的多個進程同時運行，可能也會寫入到同一個日志文件。
一般格式：
[2017－01－09 12：16：30.541][network.c:541][pid=15529]
4、有線程id。在多線程程序，如果不加線程id，很難追溯程序的行為
一般格式：
[2017－01－09 12：16：30.541][network.c:541][pid=15529][thread=0x12345]
5、有日志的級別。日志是反映問題的，有不同緊急程序的問題，自然有不同的日志級別。一般采用Error，Warning，Info，Debug。定義不同級別，也可以方便在日志查找問題來源。
一般格式：
[2017－01－09 12：16：30.541][network.c:541][pid=15529][thread=0x12345][Error]
打log的場景

1、申請內(nèi)存時，失敗的話，要把申請大小打印出來。以前我申請內(nèi)存失敗也是簡單地打印：
[2017－01－09 12：16：30.541][network.c:541][pid=15529][thread=0x12345][Error]Failed to allocate memory
后來在重構(gòu)時遇到一個問題：進程跑的時間一久，大概一天多，別的程序向它發(fā)消息都會收到失敗響應(yīng)，在日志里就是一大堆內(nèi)存失敗的消息"Failed to allocate memory"。
用"free"命令來看，物理內(nèi)存還有好幾G空閑，而用“top”命令來看，該進程也只是占700M內(nèi)存。當(dāng)時我就懷疑是不是內(nèi)存碎片導(dǎo)致。于是我把申請內(nèi)存的大小也打印出來，就收到一堆這樣的：
[2017－01－09 12：16：30.541][network.c:541][pid=15529][thread=0x12345][Error]Failed to allocate memory of size 65536
[2017－01－09 12：16：30.588][network.c:541][pid=15529][thread=0x12345][Error]Failed to allocate memory of size 1048576
當(dāng)時就看那些代碼引用的數(shù)據(jù)結(jié)構(gòu)，最小也有64K，大的16M都有，基本一個結(jié)構(gòu)包括很多個大數(shù)組。當(dāng)時就把那些數(shù)組全改為指針，再進一步申請，代碼繁瑣了，但這種問題再也不會出現(xiàn)。
再看bug系統(tǒng)，原來這個問題存在很多，在其它程序也存在，當(dāng)時都找不到根因，只是用過一段時間重啟進程來解決
2、 函數(shù)參數(shù)非空判斷時，要打印日志。原因不說，看對比：
之前：
if ( ( pInfo == NULL ) || ( pHandler == NULL ) ) 
{
    log( ERROR, "invalid arguments" );
}
之后：
if ( ( pInfo == NULL ) || ( pHandler == NULL ) ) 
{
    log( ERROR, "invalid arguments:(pInfo, pHandler )=(%p,%p)", 
            pInfo, pHandler );
}
3、加載和卸載模塊，無論是正常還是異常情況都要打印。畢竟這些操作大多都是一次性操作。對性能影響不大。
[2017－01－09 12：16：30.588][modules.c:54][pid=15529][thread=0x12345][Error]Failed to load module libftp.so, error=module already loaded
4、操作文件目錄時，失敗要把文件名和錯誤碼打印出來。如：
[2017－01－09 12：16：30.588][config.c:120][pid=15529][thread=0x12345][Error]Failed to open file conf/ftp.xml, errno=(13:Permission denied)
假設(shè)這個錯誤導(dǎo)致進程初始化失敗，且環(huán)境在客戶那邊，維護人員就可以確認并自己解決這個問題。
5、操作socket時，把IP，端口號或路徑名（Unix socket ）和錯誤碼打印出來。如：
[2017－01－09 12：16：30.588][network.c:541][pid=15529][thread=0x12345][Error]Failed to connect to host (10.17.128.10:9981), errno=(111:Connection refused)
假設(shè)在客戶環(huán)境出錯，維護人員可以根據(jù)日志來確認10.17.128.10這臺機器是否在線，是否開啟了相應(yīng)的服務(wù)，或者服務(wù)是開啟了，可能只是端口配置錯了（這種情況是扯皮最多的）
6、操作數(shù)據(jù)庫時，把相應(yīng)操作的IP，端口，庫，用戶名，sql語句和錯誤打印出來。如：
[2017－01－09 12：16：30.588][dbmgr.c:781][pid=15529][thread=0x12345][Error]user tiger failed to operate in host (10.17.128.10:3365) with db test, sql="select * from users", error="no table users exists"
在客戶環(huán)境下，維護人員可以通過命令行來驗證這些問題，來確定問題?？赡苡腥藭紤]安全性，畢竟在日志中把IP，端口，庫，用戶名都暴露出來了，這樣好像不妥。
但如果是從事過通信行業(yè)的網(wǎng)上問題維護，就知道，可維護性比這種細節(jié)的安全性還要重要。
7、創(chuàng)建新進程時，需要把程序名,參數(shù)和錯誤碼打印出來。如
[2017－01－09 12：16：30.588][process.c:154][pid=15529][thread=0x12345][Error]failed to execute program "iptables -L", errno=(2:No such file or directory)
往往在客戶環(huán)境，由于運維人員水平參差不齊，可能誤操作或漏操作，導(dǎo)致文件缺失或權(quán)限出錯，這種錯誤在公司的模擬環(huán)境根本不會出現(xiàn)。如果日志夠詳細，能夠減少很多工作量。
8、解析文件時，需要把文件名，字段，行號打印出來。如
[2017－01－09 12：16：30.588][config.c:120][pid=15529][thread=0x12345][Error]Failed to parse file conf/ftp.xml, line:20, tag <host> is not closed
結(jié)語：上面的原則，基本是每一條是血的教訓(xùn)。以前在H時見得太多因為日志不全導(dǎo)致的麻煩，前方的客戶經(jīng)理不斷向客戶懇求寬限時間，維護人員不斷地在客戶環(huán)境找出蛛絲馬跡，后方領(lǐng)導(dǎo)也不斷地調(diào)配資源來跟蹤問題，后方測試人員不斷地測試，嘗試問題復(fù)現(xiàn)，后方開發(fā)人員就不斷地看代碼。
在Z也見過因為日志不全，導(dǎo)致被客戶罰錢次數(shù)過多，整個產(chǎn)品都虧損了。像?@帝都鐵匠 說的“感覺學(xué)會log，程序就算入門了”。

????????????????  END  ???????????????
關(guān)注我的微信公眾號，回復(fù)“加群”按規(guī)則加入技術(shù)交流群。
點擊“閱讀原文”查看更多分享，歡迎點分享、收藏、點贊、在看。