天天看點

2019-7-31-程式猿修養-日志應該如何寫

title author date CreateTime categories
程式猿修養 日志應該如何寫 lindexi 2019-07-31 16:29:20 +0800 2019-7-22 9:0:54 +0800

在和小夥伴讨論日志的時候,小夥伴說的是檔案的讀寫,而實際上的日志在廣義上包含了任何的輸出方式,無論是控制台還是檔案。而日志記錄在哪不重要,重要的是什麼日志應該記錄,應該怎麼記錄和記錄什麼内容

在記日志裡面,需要嚴格将調試下的日志和釋出版的日志的記錄方法和内容分開。調試下的日志指的是在調試工具,例如在 VisualStudio 調試的時候記錄的日志,或者在自己開發裝置上調試的時候記錄的日志。而釋出版指的是将軟體通過 Release 編譯釋出給使用者端使用,此時使用者環境缺少開發工具

日志的意義

對外釋出的軟體是很難找到實時了解軟體内部是如何工作的,也很難每次都可以使用調試工具附加到軟體上。而記日志将可以讓開發者可以從日志裡面了解軟體内部是如何工作的,特别是異常等。在使用者回報問題的時候,如果這個問題是很難再次複現的,那麼除非能在調試的時候複現問題,不然在沒有日志的幫助下,是很難定位是哪裡的問題

通過軟體運作日志,可以了解到軟體在使用者端是如何運作的,可以用來回顧使用者端出現問題的時候執行的邏輯,也可以用來分析使用者的行為用于給産品提供決策

日志是什麼

在和小夥伴讨論日志的時候,小夥伴說的是檔案的讀寫,其實我和他聊的不是在一個頻道。廣義的日志包括了程式的任何輸出方式

  • 軟體界面的特殊提示,例如彈出視窗
  • 通過調試工具控制台輸出内容
  • 通過檔案記錄日志
  • 通過系統日志記錄
  • 通過上報資料到伺服器

每個方式都有自己的優點和适合用的地方,下面讓我一一告訴大家

調試下的日志

日志可以被認為是軟體運作過程中的調試工具,一個穩定的軟體一定是需要帶上運作時調試的功能

在某個測試小夥伴告訴你軟體不工作了,請問為什麼軟體不工作了?在沒有了解更多的資訊的前提下,也就是隻有上面的一句話,理論上除非你對這個軟體十分熟悉,同時也确定是你自己的某段代碼寫出來的,例如下面這個例子,否則幾乎無法定位是哪一段代碼問題

某一天林德熙逗比開發者在調試軟體的啟動過程
這個逗比開發者在軟體啟動過程中扔了一個異常
某個呂水逗比代碼審查将代碼合并到了主分支
某個洪校長釋出了這個版本
某個測試小夥伴告訴某産品說軟體不工作了,就是打不開
此時某頭像開發者直接就去打德熙逗比開發者,因為他十分明确這一定是一個逗比問題,隻有逗比開發者能寫出來      

那麼頭像開發者是怎麼知道這是一個逗比問題?而不是一個系統環境問題?在測試的裝置上,是安裝不了如此重的 VisualStudio 的,于是 ​​WPF 如何在應用程式調試啟動​​ 的方法也用不了。同時因為軟體一啟動就 gg 了,是以附加調試也用不了。就連 ​​神器如 dnSpy​​ 也被測試小姐姐說不要弄壞她的電腦不能用

此時可以怎麼知道軟體是運作做了什麼

這時就應該用上日志的功能,再次強調,一個穩定的軟體一定是需要帶上運作時調試的功能,最簡單的運作時調試功能就是記日志

最簡單的記日志的方法相信小夥伴在都用過,就是通過提示視窗,例如在寫前端頁面的時候一開始用的最多的就是彈出視窗在裡面寫調試資訊内容。當然這個方法的調試效率有點低,也不适合于在使用者端使用。下面讓我告訴大家一些好用的方法

記日志的等級

在開發的時候需要區分日志是在調試使用的還是在使用者端使用的,這兩個記錄的方法和做法都有很大的不同。有一點必須明确的是無論什麼方法記日志都是會影響性能的,其次不是所有人,特别是使用者都關心輸出的資訊,是以在調試的過程記錄的日志需要做以下區分

  • 是否隻有我關注
  • 是否隻有我在本次調試的時候才關注
  • 是否隻要調試此子產品的開發者都應該關注

上面兩個問題決定了什麼内容應該記在日志,什麼内容不應該記錄日志或者不應該将此日志内容送出到代碼倉庫

從上面問題小夥伴就知道如何考慮記日志了,對于隻有我關注的内容,也就是在我目前開發的過程我需要知道這些資訊,但其他人不需要,同時這部分資訊如果不斷輸出将會幹擾其他開發者的調試。而對于隻有我本次調試才關注的内容,也就是用在調試某個 bug 的時候,我需要進行日志輸出,而在我解決了這個 bug 那麼這些輸出内容也就不需要

在我之前開發的時候就發現了團隊項目讓 VisualStudio 輸出視窗無法使用,原因就是各個小夥伴都在往輸出視窗輸出隻有他自己關注的内容和隻有單次調試才有意義的内容。記日志不是越多越好,太多的日志資訊将會讓開發者關注不到關鍵的資訊

在我開發筆迹子產品的時候,就和雷哥合作,雷哥在他的項目裡面通過他自己搭建的日志架構,可以做到在輸出的時候指定開發者名字,隻有在對應的裝置上通過讀取系統使用者名比對才會開啟對應的日志輸出。同時他的日志架構還支援子產品日志開關,支援開啟某個子產品的日志輸出,此時就可以做到雷哥寫給自己看的日志,隻有雷哥自己看到,而其他開發者看不到。而對整個子產品的關鍵輸出,也就是任何接手這個子產品的開發者都會關注的内容,通過加上子產品标簽,可以在調試的時候在日志架構裡面開啟對應的子產品标簽進行調試,日常這些子產品調試都不會輸出,這樣不僅可以在軟體運作過程減少記日志耗費的時候,同時可以減少其他開發者看到不相關子產品的調試日志

我現在沒有找到任何一個适合和大家推薦的開源的日志追蹤架構,上面說到的雷哥的日志架構也是他自己搭建的,而我現在團隊裡面的追蹤架構我還在進行搭建

在記日志的時候,很重要的一點就是這個日志應不應該記,在問之前需要先問這個資訊屬于上面問題中的那方面資訊。如果隻是自己調試某個 bug 需要記錄的日志,那麼随意記錄,包括記錄的内容和記錄的方法。例如我在調試網絡通路的時候,我隻需要知道伺服器有沒有傳回資料而我不關注伺服器傳回的是什麼,此時我記錄的日志可以是 ​

​aaaaa​

​ 也就是一串隻有我自己在此時才能知道含義的輸出

這部分僅在某次調試才需要用到的日志沒有任何要求,隻要自己能懂就可以。但此部分送出應該在代碼審查上攔下,不應該送出到代碼倉庫

另一部分是隻有自己才需要知道的調試内容,這部分建議用工具或日志架構管理,例如在 VisualStudio 裡面有過濾輸出視窗的插件,通過每次在輸出的時候帶上自己的名字,然後過濾輸出視窗的方法,可以讓輸出的内容隻有自己看到

對于隻有自己才需要了解的調試内容,需要在記日志的時候帶上更多有用的資訊,本金魚君在寫隻有自己需要知道的調試内容的時候,會多寫一部分注釋,不然第二天調試就忘了内容

而對于子產品調試内容,建議的一般方法是在有調試架構的時候,通過标簽的方式輸出,而對沒有調試架構的時候,通過使用條件編譯符的方式讓隻有調試這個子產品的開發者才能看到

以上記日志的都是調試資訊,對于調試資訊應該隻有在 DEBUG 下才能執行代碼,不應該在釋出版本包含調試資訊代碼的執行邏輯

如何讓代碼在釋出版本不運作,隻有在調試下運作,請看 ​​條件編譯部落格​​

釋出版的日志

在釋出版的代碼裡面,通過輸出視窗進行記日志是很少用的方法,因為大多數釋出版都會在使用者端運作,在使用者端運作的時候最主要的是沒有開發環境。此時可選日志方案基本隻有檔案日志和追蹤輸出日志以及上報使用者資料的方法

通過将日志記在檔案适合于在使用者端發現問題之後,通過日志看到使用者的裝置上軟體是如何運作的。例如有使用者告訴我程式某個功能無法使用,我可以通過日志發現是我請求了伺服器,然後伺服器沒傳回,隻是就可以快速定位是伺服器或網絡相關的問題而不是定位是功能本身界面的問題

但是檔案日志應該檢視不容易,同時也不支援實時調試,是以通過追蹤記錄日志就在這裡用到。在調試需要實時看到輸出資訊的,例如有使用者告訴我他的某個功能不能用了,我遠端他的裝置,此時我需要實時看到軟體運作的輸出,那麼推薦使用以下方法。在程式關鍵點通過 ​

​Trace​

​ 靜态類作為追蹤輸出,然後在使用者端使用 ​

​DebugView​

​ 工具就可以拿到程式裡面的追蹤輸出

另外不是所有的使用者都會在軟體出現問題的時候回報到工程師,同時也不是所有使用者回報的問題都是需要解決的。需要通過使用者數量等判斷優先級,此時就需要用到上報資料的方式。在微軟釋出每個版本的系統的時候,在每次上新功能之前,都需要添加很多埋點,這裡的埋點的意思是将資料上傳到自己的伺服器。上傳的資料包括一些異常和使用者行為,以及開發認為一些不會進入的邏輯或運作性能。這樣就可以在背景分析資料知道了功能的穩定性,同時還可以知道使用者是如何使用軟體

一個成熟的軟體一定需要有成熟的日志管理方法,對于日志包含了所有程式對開發端輸出的内容而與具體形式無關。在日志管理裡面主要的是團隊約定和管理方面,本身沒有多少技術含量,即使是選用某個日志架構。也許現在我無法給大家推薦一個日志架構也和這個原因有關,每個團隊每個軟體都有自身的需求,很多需求都是相反的,這也就讓一個統一的日志架構做不起來的原因,即使是再好的日志架構,也無法在一群逗逼的團隊裡面使用

說到這裡和大家講個笑話,我在開發一個有趣的 UWP 軟體的時候,我用了 NLog 這個日志架構,有一天我看到了自己的調試裝置的存儲不夠了,于是我就想到了一個好用的功能,我需要在軟體裡面添加清理空間的功能。軟體的清理空間的功能是這樣做的,通過 NLog 不斷輸出 林德熙是逗比 讓磁盤的空間不足,于是就會執行自動的清理。同時我的日志本身也會自己清理,這樣就完成了清理空間的功能

記日志方式

說到記日志,其實日志隻是輸出的内容,至于記的方法可以有多樣,用的最多也是記最快的是通過輸出視窗記錄,建議的方法是通過 ​

​Debug​

​ 靜态類進行記錄而不是通過 ​

​Console​

​ 靜态類進行記錄。原因有二,第一是 ​

​Debug​

​ 靜态類隻有在調試下才能被執行,在釋出版将不會執行調試輸出的代碼,這樣可以提升性能。第二是 ​

​Debug​

​ 隻有調試下輸出而 ​

​Console​

​ 将會在釋出版輸出,同時任何其他程序可以通過調起軟體的方法拿到軟體程序的控制台輸出,這樣不僅會影響自己軟體在釋出版的運作性能,同時也會讓其他開發者可以知道軟體内容運作邏輯,詳細請看​​C# 如何寫 DEBUG 輸出​​

檔案記錄

另外的記日志的方法是通過檔案記錄和通過追蹤記錄,一般檔案記錄在于大量調試資訊的記錄以及在有一群逗逼小夥伴幹擾了輸出視窗的前提下,不得不自己建立一個檔案用于記錄日志。當然在進行多程序調試的時候也會用到檔案日志的方法

通過檔案記錄的方法在伺服器端推薦使用 Log4Net 架構,這個架構不僅支援檔案記錄還可以記錄到資料庫和做分布式記錄等

在用戶端的檔案記錄推薦使用 NLog 架構,這個架構不僅可以在 WPF 和 WinForms 使用,還支援在 UWP 使用

追蹤記錄

還有一個日志記錄方法是通過追蹤記錄,在 .NET 提供的 ​

​Trace​

​ 靜态類就是追蹤日志的功能,需要說明的是追蹤這個功能預設在釋出版和調試版都是執行代碼的,同時任何調試工具都可以擷取追蹤輸出,是以請不要在追蹤輸出會影響性能的内容,也不要輸出關鍵内容

如何記錄追蹤請看代碼

using System.Diagnostics;

    Trace.WriteLine("歡迎通路我部落格 https://blog.lindexi.com 裡面有大量 UWP WPF 部落格");      

詳細請看

​​dotnet core 輸出調試資訊到 DebugView 軟體​​

​​WPF 調試 獲得追蹤輸出​​

寫系統日志

對于綠色單檔案軟體,隻有一個 exe 檔案,一般小夥伴都會将這個檔案放在 U 盤或桌面,同時也沒有很高的權限,此時寫檔案不太清真,因為寫入了檔案日志,小夥伴也不知道寫在哪裡。此時一個建議的儲存地方是系統日志

​​

2019-7-31-程式猿修養-日志應該如何寫

如何寫系統日志請看 ​​C# 寫系統日志​​

上傳伺服器

這部分需要伺服器的支援,詳細請看 關于日志的那些事兒 - 衣舞晨風 - CSDN部落格

日志的内容

日志的内容應該如何寫?在上文已經告訴大家在一開始調試下一次性的調試内容可以随意寫,隻需要保證自己一時的使用,但是稍微遵循一下套路可以讓日志更好用

關鍵的日志要有明顯的不同

通過控制台輸出的時候,例如在執行到一段關鍵的邏輯,需要快速看到這段代碼。而在很有子產品都在控制台輸出的時候,如何快速找到關鍵的輸出

此時可以讓輸出的内容有明顯的不同,例如下面的輸出,請看業務輸出3 輸出多少次

業務輸出1
業務輸出1
業務輸出1
業務輸出1
業務輸出2
業務輸出1
業務輸出3
業務輸出1
業務輸出1
業務輸出3
業務輸出1      

其實很難很快找到輸出,特别是在刷屏的時候,如果使用下面的做法,那麼就很快找到

業務輸出1
業務輸出1
業務輸出1
業務輸出1
業務輸出2
業務輸出1
========== 業務輸出3 ==========
業務輸出1
業務輸出1
========== 業務輸出3 ==========
業務輸出1      

幾乎瞬間你就找到了關鍵的輸出

套路就是使用長長的符号或分割線作為辨別

隻有存在長長的符号,那麼在刷屏的時候,可以快速看到邏輯開始和結束,同時也可以快速發現存在有邏輯結束之前沒有開始

++++++++++++++ 邏輯開始 ++++++++++++
業務輸出1
業務輸出1
業務輸出1
===============邏輯結束=============
++++++++++++++ 邏輯開始 ++++++++++++
業務輸出1
業務輸出1
業務輸出1
===============邏輯結束=============
業務輸出1
業務輸出1
業務輸出1
===============邏輯結束=============      

另一個套路是添加序号,在需要執行很長的一段步驟的時候,添加序号可以明确知道執行到哪。如下面代碼可以看到存在一個連續的步驟沒有被執行

1. 業務輸出
2. 業務輸出
3. 業務輸出
4. 業務輸出
5. 業務輸出
7. 業務輸出      

标簽

我建議的輸出是帶上子產品的标簽,這樣可以用于寫腳本或程式解析和分析日志資訊,同時也可以用于過濾日志内容。特别在一開始團隊沒有管理好日志的時候,想要在現有團隊的日志裡面添加自己的内容,同時想要自己添加的内容能友善找到,此時應該使用标簽的方式

如下面的日志輸出内容,在我自己的子產品添加子產品标簽,此時雖然日志很亂,但是我依然可以通過過濾标簽的方式找到我自己的輸出内容

林德熙是逗比
[子產品] 業務輸出
林德熙是逗比
林德熙是逗比
林德熙是逗比
[子產品] 業務輸出
林德熙是逗比      

隻需要通過 ​

​\[子產品\]\s(.+)​

​ 正則就可以比對出所有我自己子產品的輸出内容

在做解析和分析的時候,也可以友善通過特定标簽找到對應的資訊

結構化日志

在記錄到檔案和上傳到伺服器等的日志建議是結構化記錄,這樣友善分析

如果一個日志檔案裡面包含了多個不同的結構和格式,那麼解析起來的難度肯定比一個結構化的日志檔案難的多,如下面兩個不同的日志格式,請問解析哪個比較簡單

// 日志1

// 格式 yyyy-mm-dd hh:mm:ss [子產品1] 内容
20190723 08:21:31 [子產品] 業務輸出

// 日志2
// 沒有格式
2019年7月21日 8:23:23 林德熙是逗比
20190725 林德熙不是逗比
0725 林德熙是逗比
内容還需要換行
8:25 這一行有10000個字元      

我有一個小夥伴說他在實習的時候的任務就是解析日志檔案,請問哪個日志檔案解析可以在一瞬間完成

使用結構化的日志可以友善後續的分析,特别是使用者很多日志很多,也期望使用大資料的方式分析的時候,在一開始寫日志就需要約定好格式,按照格式寫日志

關鍵點

日志的内容,無論是在釋出版還是調試版,在期望是用來定位的時候有以下套路包含關鍵點

時間點

建議在日志裡面添加時間點

時間點可以用來定位是不是最近發生的,以及多線程之間的執行順序。用一個反面例子告訴大家為什麼需要添加時間點

我有一個按鈕,點選的時候會做一個動畫,我會在按鈕按下的事件記錄日志,但是我沒有給記錄的日志添加時間,在某一次測試小夥伴告訴我,點選按鈕的時候沒有做動畫。而此時我看到的日志是這樣的

按鈕點選
按鈕點選
按鈕點選
按鈕點選
按鈕點選      

請問我的界面沒有做動畫是按鈕事件沒有觸發,還是動畫子產品沒有做動畫?其實我是不能确定的,如果小夥伴認為在日志裡面有看到按鈕點選這個記錄就認為按鈕事件觸發,這是不對的。可能是測試小夥伴在之前一天點選按鈕記錄的日志。使用者和測試小夥伴的話都是不可信的,隻有日志和視訊才是可信的

如果此時我添加了一些時間點,那麼我就可以知道是不是在測試小夥伴按下的時候觸發了事件,而動畫子產品沒有做動畫,還是按鈕事件沒有觸發

2019年7月25日 8:28:35 按鈕點選
2019年7月25日 8:28:37 按鈕點選
2019年7月25日 8:28:40 按鈕點選
2019年7月25日 8:28:42 按鈕點選
2019年7月25日 8:28:50 按鈕點選      

目前時間是 2019年7月26日 也就是其實今天是沒有任何按鈕事件觸發的,這時的日志才有用

線程号

在程式有多線程和多程序的時候,建議在關鍵的代碼添加對應的線程号和程序号,例如下面一個反面例子

業務開始
業務開始
// 忽略一些日志
業務結束      

此時可能認為是業務方法多次進入業務開始,一個方法存在重入,在還沒有執行完成的時候重複進入了方法,如下面邏輯

public void Foo()
{
  Log("業務開始");
  // 一些邏輯
  // 但不确定是否存在這樣的路徑 F1->F2->Foo
  F1();
  Log("業務結束");
}      

此時在 Foo 裡面調用 F1 方法,但不能确定是否在 F1 裡面會調回 Foo 方法,如果在從 F1 整個調用鍊都打上日志,那麼就和切面程式設計給每個進入方法打日志差不多,日志将會很長

如果此時添加進了線程号,那麼很快就可以知道是方法重入還是多線程調用

[99] 業務開始
[2]  業務開始
// 忽略一些日志
[99] 業務結束      

上面的數字表示的是線程号,通過線程号就可以從上面日志看到是多線程問題

次數

還是重複的調某個方法的問題,通過添加次數可以區分目前是第幾次的邏輯,例如還是下面的代碼,将會在 Foo 調用 F1 的時候重複進入 Foo 方法,那麼此時在看日志的時候應該添加目前是第幾次調用,進而可以知道在第幾次調用的時候的邏輯

public void Foo()
{
  Log("業務開始");
  // 一些邏輯
  // F1->F2->Foo
  // F1->Foo
  F1();
  Log("業務結束");
}      

添加了次數的記錄如下

次數 0 業務開始
次數 0 調用 F1 方法
次數 1 業務開始
次數 1 調用 F1 方法
次數 2 業務開始
次數 2 調用 F1 方法
次數 2 調用 F2 方法
次數 2 業務結束
次數 1 調用 F2 方法
次數 1 在 F2 方法裡面出現異常
// 忽略一些日志
次數 0 業務結束      

此時對比上面日志和自己默默删除前面的調用次數之後的日志看這兩個日志哪個找到調用鍊簡單

通過添加次數可以快速找到出現問題的調用次數和邏輯

分支

在記錄日志的時候需要考慮好分支,也就是在看到日志内容的時候,可以明确方法的邏輯。當然這個要求在調試下是不使用的,因為調試下是對大量不明确的代碼進行記錄,同時如果寫入内容不能明确,最多也就是進行修改代碼再次調試

在日志裡面考慮好分支主要是用在釋出版的日志,也就是在看到日志的時候,最好不要存在多個含義的路徑,例如下面代碼

public void Foo()
{
  if(判斷邏輯)
  {
    Log("業務");
  }
  else
  {

  }
}      

此時如果發現日志裡面不存在業務的記錄,那麼請問是 Foo 方法沒調用還是判斷邏輯沒成立,其實通過此時的日志是不能确定的

日志不是寫隻給自己看

在寫日志内容的時候,需要明确這個日志是寫給誰看,這一點将會關系到日志的内容。如果這個日志是寫給我自己看到的,那麼我可以在日志裡面使用大量的代号,如下面日志

aaaaaaaaaaaa
xxxxxx
=========      

相信看到上面日志的小夥伴是很難知道我表達的是什麼,即使他告訴我程式無法使用了,他自己看到了日志也不知道為什麼程式無法使用

在寫日志的時候,建議按照日志是寫給誰看的,決定寫的内容

  • 寫給相關開發者

    相關開發者也就是他也參與了子產品的開發,那麼日志内容可以包含一些細節部分,最簡單的就是通過 AOP 切面程式設計,将每個調用方法輸出

    但是通過 AOP 切面程式設計輸出的日志就和調用堆棧差不多,經常在出現問題的時候無法從日志裡面看出問題,或者日志的内容過多,大家都不願看日志。還會讓開發者認為有 AOP 自動記日志了,自己就不用想如何記日志,這會讓日志的品質很低

  • 寫給調試相關方

    應該包含執行細節和關鍵路徑,在日志裡面的分類應該是 Debug 級

    相關的調試方是将會調試你寫的子產品或庫的開發者,對于調試方應該認為子產品或庫是白盒也就是他應該知道子產品或庫的狀态,同時調試相關方也隻有在調試下才需要使用到日志

  • 給未穩定程式或輔助程式寫日志而使用方是相關開發者

    對相關開發者是不關注他使用的未穩定程式或輔助程式到底在做什麼,隻關注完成了什麼,和為什麼出錯了。此時應該執行細節輸出,友善相關開發者在程式不穩定的時候調試。或者友善在相關開發者使用過程發現問題的時候,将你拖過來,可以通過日志内容快速知道是什麼問題以平息相關開發者怒氣。或者友善相關開發規避未穩定程式的坑,按照執行邏輯寫出預定輸入

  • 提供給上層開發者調用底層庫的日志

    應該輸出關鍵路徑和錯誤資訊,在使用庫的時候上層開發者是不關注除了錯誤之外的其他資訊

    但也需要提供關鍵路徑輸出的手段,友善上層開發者調試。在寫這部分日志資訊的時候需要假定自己使用這個底層庫的開發者,如何通過輸出的日志資訊調試。也就是調試資訊預設處于關閉,應該提供開關讓相關開發開啟底層庫調試輸出

    作為底層庫的輸出需要非常仔細,很多時候的建議隻是輸出錯誤資訊,其他的都不要輸出,因為一旦輸出開發者不關心的内容,那麼開發者将會認為底層庫弄亂了輸出視窗或日志檔案。同時底層庫除非提供安全開關否則不應該将敏感資訊輸出。例如我有一個網絡子產品的庫,如我在輸出日志裡面包含了秘鑰那麼所有引用我這個庫的開發者将可以拿到秘鑰做有趣的通路

  • 應用程式的子產品

    應該輸出可供調試的日志内容,以及非預期的運作過程和運作關鍵路徑記錄。和與其他子產品之間的通信記錄

    通過換個想法,在我的程式出現異常的時候我如何根據日志資訊定位是哪個子產品的問題,就可以知道應該輸出的可供調試的内容是什麼。這部分可以依照經驗所做,很少可以做到一次性做對,一般都是在出現問題之後發現之前記錄的内容不夠分析,然後才不斷優化

    很多小夥伴都習慣将預期的内容作為日志内容,其實日志應該更多包含非預期的運作,也就是在 if 後面的沒有寫的 else 才是日志的關鍵内容,一般非預期的行為将會出現沒有覆寫的測試,此時的日志将可以協助了解非預期的行為是如何做的

    與其他子產品之間的通信記錄主要用來甩鍋,特别是在多程序和軟硬體開發的時候,請将和對方通信的路徑輸出,友善知道是哪一方的問題。這裡的多程序開發包含了在同裝置的多個程序以及通過網絡通路背景這些都需要添加足夠的日志記錄,友善知道是自己的子產品發送的不對還是對方傳回的不對

    在程式中運作關鍵路徑記錄可以用于了解程式運作到哪個步驟,例如啟動過程的日志,如果軟體運作就直接退出,那麼請問是運作到哪就退出?此時通過關鍵運作步驟就可以知道運作了多少步,進而知道運作到下一步是哪一步的時候退出。在我調用 C++ 庫的時候也是這樣做的,在 Windows 裡面如果 C++ 庫通路了沒有權限的内容,那麼系統将會幹掉這個程序,于是我在調用的時候都會先記錄日志說開始調用,如果我發現程式退出了,而沒有在日志找到調用完成那麼就可以知道我調用的 C++ 庫讓我的程式直接退出

  • 應用程式的輸出

    預設按照等級分類輸出,不要輸出程式細節,需要提供可供調試日志

    建議隻輸出錯誤和非預期行為和關鍵行為

    建議提供調試開關,用于在使用者端調試程式。例如 Office 就提供了在指令行啟動可以開啟調試輸出,開啟的時候将會輸出很多調試日志

    應用程式是作為釋出到使用者端的程式,建議添加的日志不要太多,一個反面例子就是 TIM 寫入太多的日志

    很多程式都沒有提供調試開關,這樣會讓程式需要在日志裡面要麼包含一些調試資訊,要麼無法在使用者端調試,需要通過工具才能調試,效率比較低

  • 給 FAE 售後服務人員看的日志内容

    輸出出錯原因而不應該包含程式運作細節

    因為售後服務不關注也不會了解程式運作細節,反而這些細節内容可能被競争對手利用。例如 HH 公司知道我的軟體需要依賴硬體部分發送正确滑鼠消息,于是就通過模拟詭異的滑鼠消息讓我的軟體無法使用

  • 上報伺服器用于分析的内容

應該輸出結構化可分析内容,減少背景清洗資料的難度,同時需要上報的是盡量是中繼資料,也就是多個資料之間沒有關系,減少上報的資料

上報伺服器的内容需要明确背景期望分析什麼然後再決定如何上傳,上傳的資料建議不要太多

如果不明确背景期望分析什麼的時候,需要将盡可能多的中繼資料上報。這裡需要強調一點的是,上報的資料不是越多越好,需要根據使用者量和背景技術實力上報合适的資料

應該在哪寫日志

從上文可以了解到日志的内容應該寫什麼,但有一些套路和推薦可以告訴大家應該在哪裡寫日志

多平台調用

在上文也有提到,在多端聯調的時候,日志是關鍵,不僅用于解決問題更多的用于甩鍋

如在調用背景的時候,無論是在調試的過程還是在釋出版本都應該有一定的日志記錄,這樣友善知道是用戶端的問題還是伺服器端的問題還是網絡的問題

在進行多平台調用的時候,不僅是通路背景的部分應該記錄日志,對于大部分硬體的通信也應該記錄日志。例如我有一個功能是從攝像頭擷取圖檔,此時我應該在尋找攝像頭,從攝像頭擷取圖檔以及擷取到或沒有擷取到等的分支都添加上日志。這樣在使用者端或在調試的時候發現用戶端沒有預期擷取到圖檔時,可以了解到是連接配接攝像頭失敗還是連接配接成功但沒有擷取到圖檔等

又例如我調用 git 指令行執行一段指令,我應該将指令行調用的參數和 git 程序執行的輸出都記錄,這樣在調用 git 指令沒有執行的時候,可以知道是否傳入的指令行參數不對還是 git 沒有安裝

基本上可以認為和其他平台,也就是和非自己代碼執行邏輯的部分,和非目前裝置執行的部分,在調用前後需要記錄相關的内容,包括調用狀态和參數

全局未捕獲異常

在 dotnet 裡面提供了多個全局異常捕獲方式,如果有一個異常在代碼抛出,同時沒有任何地方接住這個異常,那麼這個異常将會成為全局未捕獲異常

一般隻有開發過程中未考慮到的異常才會作為全局未捕獲異常,同時也一般隻有在團隊裡面有​​好的規範​​處理異常的時候,全局未捕獲異常才有用

推薦将全局未捕獲異常記錄,同時記錄的方式建議同時記錄在本地檔案和上報到伺服器,因為有很多代碼路徑隻有大量的使用者使用的時候,才能在使用者端觸發,而在開發端是很難測試到

更多關于異常請看 ​​一文看懂 .NET 的異常處理機制、原則以及最佳實踐 - walterlv​​

​​配置 legacyUnhandledExceptionPolicy 防止背景線程抛出的異常讓程式崩潰退出 - walterlv​​

關鍵分支

在代碼裡面如果有進入一些關鍵分支,那麼建議進入的時候添加日志

這裡的關鍵分支主要是業務上的定義,例如使用者删除一個檔案,此時需要添加一條記錄。至少可以做到在使用者噴垃圾軟體删除我的檔案的時候,可以從日志裡面找到這是使用者自己的行為

未命中分支

在很多開發代碼裡面隻有對參數正确做判斷執行邏輯,而對參數非預期時沒有判定,也就是通常說的 else 分支

如果在開發的時候确認這個過程不會進入 else 分支,那麼依然建議在未命中分支裡面添加日志,萬一命中了,那麼意味着存在一條有趣的路徑。在記錄未命中分支的時候,建議将調用堆棧和參數都記錄

記錄目前調用堆棧方法​​WPF 判斷調用方法堆棧​​

全局關鍵設定項

全局關鍵設定項例如設定 dll 尋找路徑或一些全局業務設定,建議在進入設定的時候添加日志,這樣可以知道是哪個子產品調用,以及調用原因

特别是一些庫提供的全局關鍵設定項,例如在某個業務執行下面代碼的時候,于此不相關的其他業務都會受到影響

Environment.CurrentDirectory = "C:\\lindexi";      

這樣的全局關鍵項設定之前,建議添加日志,這樣友善進行調試

如果以上代碼沒有添加日志,那麼幾乎找不到是哪個做的設定,也幾乎在出現找不到檔案的時候不知道是因為有開發者修改了目前的工作檔案夾

手動關閉應用程式

在 dotnet 程式裡面有很多手動退出程式的方法,因為是手動退出程式,是以一般是不會存在任何異常和 DUMP 等。如果是一些邊緣業務調用了退出程式,那麼在沒有記錄日志的時候,很難猜到是手動退出程式

建議在所有手動退出程式的地方都添加上日志,這樣友善知道目前是進行手動退出

我遇到一個問題是應顔小夥伴告訴我他的軟體會莫名退出同時沒有找到任何日志和系統事件,我通過了很多工具都沒有找到對應的問題,經過了幾個小時在 dnspy 在 Environment.Exit 函數裡面添加斷點才找到原來是有業務調用了關閉程式

與不穩定庫之間調用

特别是調用 C++ 庫的時候,如果這個 C++ 庫寫的不清真,那麼可能系統将會直接幹掉程序,此時任何日志等都無法記錄,也就是莫名軟體退出的第一個應該猜的可能

建議在調用之前添加日志,調用完成之後添加日志,這樣在軟體莫名退出的時候可以知道原來是通路了不穩定的庫

而如果還需要知道為什麼調用不穩定庫的時候,将會退出,那麼建議也将傳入的參數記錄一下。例如我有一個 C++ 庫裡面需要傳入字元串,而我在開發的時候測試都是可以通過,但是在使用者端發現一調用軟體就退出了。通過日志我看到了在軟體退出之前我調用的時候傳入的字元串是中文但開發的時候傳入的是英文這是就知道了這個庫的參數支援傳入的字元串

委托線程的開啟

在進行 Task 調用一段代碼的時候,如果這個代碼出現了問題,那麼從調用堆棧幾乎看不出是從哪裡發起的邏輯

class Foo
        {
            public void Run()
            {
                Task.Run(() =>
                {
                    // 運作代碼
                });
            }
        }      

例如上面代碼,如果在 運作代碼 裡面執行了不符合預期的代碼,那麼此時将難以知道是哪個業務調用了 Run 方法,因為在調用堆棧是找不到調用 Run 方法

建議在調用線程之前記錄一下是哪裡調用

總結一下,寫日志不是簡單将日志寫到檔案,更多的是管理的問題,寫日志有多個方式有不同的用途,需要按照日志是給誰看的寫不同的内容

我對一個團隊的項目在日志部分的評分是這樣,隻要有日志就完全達到90分,而日志内容和規範等隻是很少的加分

2019-7-31-程式猿修養-日志應該如何寫

是以,寫日志這部分重要的是開始

繼續閱讀