程序員的修養 -- 如何寫日志(logging)


原文地址
https://blog.csdn.net/lk142500/article/details/80424945
https://www.cnblogs.com/sentakee/p/5630466.html

1 簡介
在程序中寫日志是一件非常重要,但是很容易被開發人員忽視的地方。寫好程序的日志可以幫助我們大大減輕后期維護壓力。在實際的工作中,開發人員往往迫於巨大時間壓力,而寫日志又是一個非常繁瑣的事情,往往沒有引起足夠的重視。開發人員應在一開始就養成良好的日志撰寫習慣,並且應在實際的開發工作中為寫日志預留足夠的時間。

1.1 日志的作用
一般程序日志出自下面幾個方面的需求:

  1. 記錄用戶操作的審計日志,甚至有的時候就是監管部門的要求。
  2. 快速定位問題的根源
  3. 追蹤程序執行的過程。
  4. 追蹤數據的變化
  5. 數據統計和性能分析
  6. 采集運行環境數據
    一般在程序上線之后,一旦發生異常,第一件事就是要弄清楚當時發生了什么。用戶當時做了什么操作,環境有無影響,數據有什么變化,是不是反復發生等,然后再進一步的確定大致是哪個方面的問題。確定是程序的問題之后再交由開發人員去重現、研究、提出解決方案。這時,日志就給我們提供了第一手的資料。
    1.2 撰寫日志的要求
    既然撰寫日志是有需求,而且也能在未來幫助我們提高工作效率的事情,長遠來看是非常有利的一件事情。因此我們應該在自己開發的程序中符合規范的撰寫日志,在寫日志時要注意以下的問題。
    1.2.1 日志的可讀性
    日志時給人讀的,不僅僅是讓自己明白,也要讓沒有接觸過我們源代碼的其他程序員也能夠一目了然。有的同事在日志中打印特殊的標識符號,例如“++++++++++”, “===========”,“—————”,這些符號令人眼花繚亂。這是一種不好的編程習慣。
    另外,把日志分類輸出到不同的文件也有利於我們排除干擾,迅速找到我們需要的信息。而且,最好在打印日志時輸出英文,防止中文不支持而打印出亂碼的情況。

1.2.2 日志的性能
無論我們把日志寫到文件還是數據庫,都需要消耗IO資源。適當的控制日志的輸出也有利於提高程序的性能。例如:盡量避免在在大的循環中打印意義不大的日志內容。輸出日志之前最好能判斷日志的級別(例如. debug前先調用isDebugEnabled()作出判斷)。
1.2.3 占用磁盤空間
通常,我們都是把日志寫入磁盤上的日志文件中。適當的使用滾動日志並且定時清除舊文件是有好處的。我見過這樣一個例子,程序運行幾次后就跑不起來了,前幾次都是正常的。怎么都想不明白程序有什么問題,最后才發現居然是日志文件占滿了磁盤空間。在實際的應用中出現上G的日志文件也往往不少見。要在這樣規模的日志文件中找出對解決問題有用的信息也是一大挑戰。
1.2.4 日志的時效性
有的時候我們並不能及時的發現問題。需要追溯之前的日志。所以我們是需要保留一段時間以內的日志便於追溯。
1.2.5 日志級別
通常我們在產品環境中日志的級別都在INFO以上,所以我們必須保證在這樣的情況下程序仍然能夠輸出足夠我們作出判斷的信息。
例如常見的系統具有如下的日志級別:

// 定義FATAL級別輸出宏
#define DRV_LOG_FATAL(fmt, ...)           hlog_format(HLOG_LEVEL_FATAL, "PluginDriver",   "[%s(%d)] "fmt, __FUNCTION__,   __LINE__, ##__VA_ARGS__)

// 定義ERROR級別輸出宏
#define DRV_LOG_ERROR(fmt, ...)           hlog_format(HLOG_LEVEL_ERROR, "PluginDriver",   "[%s(%d)] "fmt, __FUNCTION__,   __LINE__, ##__VA_ARGS__)

// 定義WARN級別輸出宏
#define DRV_LOG_WARN(fmt, ...)          hlog_format(HLOG_LEVEL_WARN, "PluginDriver",   "[%s(%d)] "fmt, __FUNCTION__,   __LINE__, ##__VA_ARGS__)  

// 定義INFO級別輸出宏
#define DRV_LOG_INFO(fmt, ...)          hlog_format(HLOG_LEVEL_INFO, "PluginDriver",   "[%s(%d)] "fmt, __FUNCTION__,   __LINE__, ##__VA_ARGS__)  

// 定義DEBUG級別輸出宏
#define DRV_LOG_DEBUG(fmt, ...)           hlog_format(HLOG_LEVEL_DEBUG, "PluginDriver",   "[%s(%d)] "fmt, __FUNCTION__,   __LINE__, ##__VA_ARGS__)   
// 定義TRACE級別輸出宏
#define DRV_LOG_TRACE(fmt,   ...)         hlog_format(HLOG_LEVEL_TRACE, "PluginDriver",   "[%s(%d)] "fmt, __FUNCTION__,   __LINE__, ##__VA_ARGS__)  

上述的日志文件中定義了6種日志級別,不同級別的含義在下文詳述,需要了解到在一個程序開發的過程中需要維護不同的分別為FATAL, ERROR, EARN, INFO, DEBUG, TRACE。
1.2.6 日志內容
我們在寫日志的時候,需要注意輸出適當的內容。首先,盡量使用業務相關的描述。我們的程序是實現某種業務的,那么就最好能描述清楚這個時候走到了業務過程的哪一步。其次,避免在日志中輸出一些敏感信息,例如用戶名和密碼。以及,要保持編碼的一致。如果不能保證就盡量使用英文而不是中文。這樣當我們拿到日志之后就不會因為看到一堆亂碼而不知所雲了。
1.2.7 日志格式
常見的日志格式中對於每一條日志應含有的信息包括日期、時間、日志級別、代碼位置、日志內容、錯誤碼等信息。下面是一個工作中的日志文件的一部分內容:

2018-05-22 15:35:53.850 TRACE TDWZLog [0x00001b10] <36> <TDWZProtocol::Init>,TDWZProtocol::Init
2018-05-22 15:35:53.850 TRACE TDWZLog [0x00001b10] <89> <TDWZProtocol::Init>,End in processing TDWZProtocol::Init
2018-05-22 15:35:53.853 TRACE TDWZLog [0x00001b10] <142>    <TDWZProtocol::Connect>,Connect Execute finish
2018-05-22 15:35:53.853 TRACE TDWZLog [0x00002f10] <149>    <GetAlarmEventPro>,Enter GetAlarmEventPro func
2018-05-22 15:39:36.382 WARN TrackLog [0x000029fc] - [ internal WARN htrace_server_convert_msgstring_to_contextintls(493) ] detect input id error, trace_id span_id,this chain may not be tracked.
2018-05-22 15:39:36.383 WARN TrackLog [0x000029fc] - [ internal WARN htrace_server_receive(195) ] can not detect trace_id in context, this chain may not be tracked.
2018-05-22 15:39:36.383 TRACE TDWZLog [0x000029fc] <231>    <TDWZProtocol::DisConnect>,TDWZProtocol::DisConnect
2018-05-22 15:39:37.502 TRACE TDWZLog [0x00002f10] <225>    <GetAlarmEventPro>,End Get AlarmEventPro Func
2018-05-22 15:39:37.503 TRACE TDWZLog [0x000029fc] <241>    <TDWZProtocol::DisConnect>,close socket
2018-05-22 15:39:37.503 TRACE TDWZLog [0x000029fc] <242>    <TDWZProtocol::DisConnect>,Execute DisConnect function succeed.

可以從該文件中看出一般日志文件中應該含有的信息。

2 日志級別和含義
Log4j是Apache的一個開源項目,通過使用Log4j,我們可以控制日志信息輸出目的地是控制台、文件、GUI組件甚至是套接口服務器;我們也可以控制每一條日志的輸出格式;通過定義每一條日志信息的級別,我們能夠更加細致地控制日志的生成過程。最令人感興趣的就是,這些可以通過一個配置文件來靈活地進行配置,而不需要修改應用的代碼。
2.1 Log4j的組成
Log4j由三個重要的組成構成:日志記錄器(Loggers),輸出端(Appenders)和日志格式化器(Layout)。
2.1.1 Logger
控制要啟用或禁用哪些日志記錄語句,並對日志信息進行級別限制
2.1.2 Appenders
指定了日志將打印到控制台還是文件中.
2.1.3 Layout
控制日志信息的顯示格式。
2.2 日志級別
Log4j中將要輸出的Log信息定義了6種級別,依次為TRACE、DEBUG、INFO、WARN、ERROR和FATAL,當輸出時,只有級別高過配置中規定的 級別的信息才能真正的輸出,這樣就很方便的來配置不同情況下要輸出的內容,而不需要更改代碼,非常方便快捷。
2.2.1 TRACE
TRACE designates finer-grained informational events than the DEBUG.Since:1.2.12,很低的日志級別,一般不會使用。TRACE一般跟蹤的是函數的調用,並且TRACE不應該含有變量參數,而僅能提示函數的調用關系。
2.2.2 DEBUG
一般用於細粒度級別上,對調試應用程序非常有幫助,主要用於開發過程中打印一些運行信息。
2.2.3 INFO
INFO消息在粗粒度級別上突出強調應用程序的運行過程。打印一些你感興趣的或者重要的信息,這個可以用於生產環境中輸出程序運行的一些重要信息,但是不能濫用,避免打印過多的日志。
2.2.4 WARN
WARN表示會出現潛在錯誤的情形,有些信息不是錯誤信息,但是也要給程序員一些提示。該級別表示程序會自動調整到正常的狀態,類似參數未傳入,使用了默認的參數,仍符合程序員預期之內的情況。
2.2.5 ERROR
ERROR指出雖然發生錯誤事件,但仍然不影響系統的繼續運行。打印錯誤和異常信息,如果不想輸出太多的日志,可以使用這個級別。一般在WARN之后的級別在打印錯誤時,應該同時打印錯誤碼。
2.2.6 FATAL
FATAL指出每個嚴重的錯誤事件將會導致應用程序的退出,這個級別比較高,重大錯誤,程序無法恢復,必須通過重啟程序來解決。
2.3 日志級別大小關系
日志級別就像開關一樣,來決定哪些日志方法被調用,哪些不被調用。在log4j中,日志級別的關系如下所示:

ALL<TRACE<DEBUG<INFO<WARN<ERROR<FATAL<OFF

設置了對應的級別之后,日志框架就只調用大於等於這個級別的方法。Log4j建議只使用如下的四個界別

DEBUG<INFO<WARN<ERROR

3 日志規范示例
模仿,抄寫是比較好的學習方式,借鑒前人撰寫日志的良好風格以形成自己的風格是不錯的方式。下面是一些不錯的日志記錄。

3.1 TRACE日志記錄示例

DRV_LOG_TRACE("Connect Execute start");
DRV_LOG_TRACE("Connect Execute finish");
DRV_LOG_TRACE("DisConnect func");
DRV_LOG_TRACE("Execute DisConnect function succeed.");
DRV_LOG_TRACE("Enter UploadEvent Func");
DRV_LOG_TRACE("extInfo = %s", Extension);
DRV_LOG_TRACE("Send a Msg ");
DRV_LOG_TRACE("- Connect Execute start");
DRV_LOG_TRACE("- Connect Execute finish");
DRV_LOG_TRACE("- Enter GetAlarmEventPro func");
DRV_LOG_TRACE("- Receive an info");
DRV_LOG_TRACE("- End Get AlarmEventPro Func");
DRV_LOG_TRACE("- DisConnect func");
DRV_LOG_TRACE("- Execute DisConnect function succeed.");
DRV_LOG_TRACE("- Enter UploadEvent Func");
DRV_LOG_TRACE("- Leave UploadEvent Func");
DRV_LOG_TRACE("- ============電網報警觸發");
DRV_LOG_TRACE("- ============開始發送電流電壓值");
DRV_LOG_TRACE("- ============間隔超過分鍾再次發送電流電壓值");

3.2 INFO日志記錄示例

DRV_LOG_INFO("- UpdataEvent  nchal= %d,EventID = %d.",iChannelNo,nEventType);
DRV_LOG_INFO("- do not support doControl");
DRV_LOG_INFO("- channelId = %s, nStatusType = %d", channelId.c_str(), nStatusType);

3.3 DEBUG日志記錄示例

DRV_LOG_DEBUG("- 輸出報警情況:電網編號:%d,報警數量:%d,報警內容:%s.",datas.data1.chn,datas.data1.alarm_num,datas.data1.alarms);
DRV_LOG_DEBUG("- 輸出報警情況:電網編號:%d,報警數量:%d,報警內容:%s.",datas.data2.chn,datas.data2.alarm_num,datas.data2.alarms);
DRV_LOG_DEBUG("- 輸出報警情況:電網編號:%d,報警數量:%d,報警內容:%s.",datas.data3.chn,datas.data3.alarm_num,datas.data3.alarms);
DRV_LOG_DEBUG("- 輸出報警情況:電網編號:%d,報警數量:%d,報警內容:%s.",datas.data4.chn,datas.data4.alarm_num,datas.data4.alarms);
DRV_LOG_DEBUG("- ============datas.data1.huab = %d",datas.data1.huab);
DRV_LOG_DEBUG("- ============datas.data1.hiab = %d",datas.data1.hiab);
DRV_LOG_DEBUG("- ============datas.data2.huab = %d",datas.data2.huab);
DRV_LOG_DEBUG("- ============datas.data2.hiab = %d",datas.data2.hiab);
DRV_LOG_DEBUG("- ============datas.data3.huab = %d",datas.data3.huab);
DRV_LOG_DEBUG("- ============datas.data3.hiab = %d",datas.data3.hiab);
DRV_LOG_DEBUG("- ============datas.data4.huab = %d",datas.data4.huab);
DRV_LOG_DEBUG("- ============datas.data4.hiab = %d",datas.data4.hiab);
DRV_LOG_DEBUG("- Alarm is : %s",szEvent.c_str());
DRV_LOG_DEBUG("- GetChannelExtInfo channelId=%s", channelId.c_str());
DRV_LOG_DEBUG("- nChan = %d, szInfo = %s", nChan, szInfo);

3.4 WARN日志記錄示例

DRV_LOG_WARN("[0x%08x] - invaild event msg,discard it", DRV_INVALID_ARG);
DRV_LOG_WARN("[0x%08x] - Can't find channel by channelId");
DRV_LOG_WARN("[0x%08x] - [DWSdk.errorcode=0x%08x]Connect device failed", DRV_CONNECT_FAILED, sdkErrCode);
DRV_LOG_WARN("[0x%08x] - [DWSdk.errorcode=0x%08x]dw_start_receive failed", DRV_ERROR, sdkErrCode);
DRV_LOG_WARN("[0x%08x] - [DWSdk.errorcode=0x%08x]Communicate failed, socket recv error", DRV_ERROR, DW_SOCKET_RECV_ERROR);
DRV_LOG_WARN("[0x%08x] - [DWSdk.errorcode=0x%08x>other error", DRV_ERROR, iGetResult);
DRV_LOG_WARN("[0x%08x] - [DWSdk.errorcode=0x%08x>other error", DRV_ERROR, iGetResult);
DRV_LOG_WARN("[0x%08x] - SetEventCallBack should be called first", DRV_ERROR);

3.5 ERROR日志記錄示例

DRV_LOG_ERROR("Init DwSDK filded;<errCode=%d>", initRet); 
DRV_LOG_ERROR("Connect device failed");
DRV_LOG_ERROR("Create thread failed");
DRV_LOG_ERROR("dw_start_receive failed");
DRV_LOG_ERROR("Communicate failed, socket recv error");
DRV_LOG_ERROR("other error<errCode=%d>", iGetResult);
DRV_LOG_ERROR("SetEventCallBack should be called first");

DRV_LOG_ERROR("[0x%08x] - [DWSdk.errorcode=0x%08x]Init DwSDK filded", DRV_INIT_FAILED, initRet);
DRV_LOG_ERROR("- [HPR.errorcode=0x%08x]Create thread failed", HPR_GetLastError());

上述代碼中[0x%08x]有下述作用:
該語句出現於格式化輸出時的格式字符串中。形式為

"0x%08x"

其中,0x為普通字符,輸出的時候會原樣輸出為0x。
%08x為整型以16進制方式輸出的格式字符串,會把后續對應參數的整型數字,以16進制輸出。08的含義為,輸出的16進制值占8位,不足部分左側補0。
於是,如果執行

printf("0x%08x", 0x1234);

會輸出0x00001234。


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM