如何設計/使用 logger? #21

mkfsn · 2021-01-30T02:49:37Z

看起來 logger 的部分有兩種做法：

一種是在每個需要的檔案都 import 一次。
另外一種是在每個 package 裡面都 new 一次。

以記憶體使用而言，在 Logger 裡面沒有存放東西的前提下應該是相等（都是零）。
以維護的複雜度而言，其實後面修改 internal logger 裡的東西就行了。

日後如果確定將 #16 的 layout 作法合併進來後還感覺到有不足的地方時再繼續進行討論。

Originally posted by @PichuChen in #16 (comment)

itsarbit · 2021-01-30T03:09:35Z

I am more leaning toward the first option. The code could be cleaner.

asymptoter · 2021-01-30T04:06:37Z

我提供一下我習慣使用的方式：
首先會在 routing 的地方加上一個 middleware ，假設使用 gin 的話那就是

r := gin.Default()
r.USE(logging)
r.GET("/api/v1/boards", getBoards)
r.POST("/api/v1/boards", createBoard)

func logging(c *gin.Context) {
    logEntry := logging.NewLogEntry()
    ...
    // log some http request information
    ...
    c.Set("logEntry", logEntry)
}

func getBoards(c *gin.Context) {
    log := c.MustGet("logEntry").(logging.Entry)
    log = log.WithParameters()
    res, err := doSomethingMayWrong(log, parameters...)
    if err != nil {
        log.Error(err)
        // handle error
    }
}

// logging.go
var commonLogger *Logger
func init() {
    // Initiate common logger
}

func NewLogEntry() *Entry {
    return &Entry{
        Logger: commonLogger,
        Data: map[string]interface{}{},
    }
}

簡單來說就是只有一個 logger ，但每個 request 都會產生一個屬於自己的 log entry ，這些 log entry 實際上使用了相同的 logger ，在 request 結束前都是使用這個 entry 來記錄發出 log 時所需要的資料，不同的 request 間不會互相影響使用，比較接近第一個做法。

這個做法的好處是如果一個地方出錯時，你可以知道一路上他經過 function 時所帶的參數，找 bug 會變得很輕鬆。

maxjkfc · 2021-02-04T02:21:18Z

先用單例模式建立實例後，在每一次需要時都 import 使用，這是蠻簡單方便的方法。
每個階段的過程使用 context.WithValue 存放要紀錄的內容，在最後使用 log.WithContext(ctx).Error() 來將在context 內的紀錄打印出來，這也是個能找出歷程方式

PichuChen · 2021-02-04T05:29:58Z

先用單例模式建立實例後，在每一次需要時都 import 使用，這是蠻簡單方便的方法。

每個階段的過程使用 context.WithValue 存放要紀錄的內容，在最後使用 log.WithContext(ctx).Error() 來將在context 內的紀錄打印出來，這也是個能找出歷程方式

我原先的想像是沒有context 像是 syslog 那樣子的設計，但是你提到紀錄 context 的設計我認為很好。

不過紀錄 context 的話可能有兩個層次的 context 要考慮，一個是 process 等級的 context, 另外一個是 request 的 context 。

sageofcross · 2021-02-04T15:12:29Z

原生的 context 套件在使用 WithValue 時需要注意一下，它內部的實作就是個俄羅斯娃娃，而且容易演變成一個 map[interface{}]interface{} 的存在，使用時要小心點。

maxjkfc · 2021-02-04T15:43:07Z

原生的 context 套件在使用 WithValue 時需要注意一下，它內部的實作就是個俄羅斯娃娃，而且容易演變成一個 map[interface{}]interface{} 的存在，使用時要小心點。

的確沒有處理好容易會引發這個問題，這邊我可以研究一下，寫個範例跟大家討論看看，是否可以這樣處理

Markogoodman · 2021-02-05T05:19:17Z

目前在code裡面還看到滿多log的指令的，感覺可以減少一些

我覺得只要request進來後log一下相關資訊一次就好例如urlpath method ip 之類的

之後如果發生error的話再 log 即可(覺得可以只在 usecase 層 log 就好)

還有建議可以用 defer 來處理

就不必在每個 if err != nil 的地方都各自弄

func DoSomething (a, b, c) (xxx, error){
    defer func(){
        if err != nil {
            log(err, fmt.Sprintf("DoSomething, %v %v %v", a, b, c))
            return
        }
    }()
    // do something
}

asymptoter · 2021-02-05T11:13:37Z

目前在code裡面還看到滿多log的指令的，感覺可以減少一些
我覺得只要request進來後log一下相關資訊一次就好例如urlpath method ip 之類的
之後如果發生error的話再 log 即可(覺得可以只在 usecase 層 log 就好)

我不推薦 error 時只在 usercase log 一次的作法，原因是 route 層也有可能在解析 request 的 parameter 或是 body 時出錯。

還有建議可以用 defer 來處理
就不必在每個 if err != nil 的地方都各自弄

func DoSomething (a, b, c) (xxx, error){
    defer func(){
        if err != nil {
            log(err, fmt.Sprintf("DoSomething, %v %v %v", a, b, c))
            return
        }
    }()
    // do something
}

這個也不推薦，defer 的話無法知道實際發生錯誤的行數。

chhsiao1981 · 2021-02-06T02:49:04Z

可考慮

https://github.com/spf13/jwalterweatherman
https://github.com/sirupsen/logrus

Markogoodman · 2021-02-06T10:17:51Z

我不推薦 error 時只在 usercase log 一次的作法，原因是 route 層也有可能在解析 request 的 parameter 或是 body 時出錯。

抱歉我前面可能有點沒講清楚，我的想法是 delivery 層級的錯誤應該都很類似，譬如你說的解 param 出現錯誤或著是 middleware 中做 permission check的部分出錯
在整個 delivery handler 處理完後一次 log 就好
可以參考 gin middleware logger 的作法
https://github.com/gin-contrib/logger/blob/3796188ec8bf8bd11cb4589852f06433f8b117ce/logger.go#L23

這個也不推薦，defer 的話無法知道實際發生錯誤的行數。

是說這個可以舉個例子嗎?
我的想像中，一個func下面呼叫的不同func出現的錯誤應該只有少部分會相同
例如下面這個，我想說 DoSomethingA 與 DoSomethingA 他們出現的error應該會差滿多的，所以error資訊有正確紀錄的話應該還是看的出來是哪邊出錯(?

func (u *usecase) Do(param) (err error) {
    defer (){
        // 這裡可以把 error log 或是把err加上 Do 和 pararm 資訊 傳上去，或是前面有其他人提到的把err放進ctx也可以
    }
    err = repo.DoSomethingA()
    if err != nil{
        return
    }
    err = repo.DoSomethingA()
    if err != nil{
        return
    }
}

以上主要是想減少log的程式碼散落各處
順便看大家覺得這樣會不會有啥漏洞

asymptoter · 2021-02-06T11:18:50Z

抱歉我前面可能有點沒講清楚，我的想法是 delivery 層級的錯誤應該都很類似，譬如你說的解 param 出現錯誤或著是 middleware 中做 permission check的部分出錯
在整個 delivery handler 處理完後一次 log 就好
可以參考 gin middleware logger 的作法
https://github.com/gin-contrib/logger/blob/3796188ec8bf8bd11cb4589852f06433f8b117ce/logger.go#L23

是說這個可以舉個例子嗎?
我的想像中，一個func下面呼叫的不同func出現的錯誤應該只有少部分會相同
例如下面這個，我想說 DoSomethingA 與 DoSomethingA 他們出現的error應該會差滿多的，所以error資訊有正確紀錄的話應該還是看的出來是哪邊出錯(?

疑惑為什麼同一個 function 出現的 error 會差滿多這件事，與此相關想問要怎麼區分 error 發生在上面的 DoSomethingA 還是下面的 DoSomthingA ？

func (u *usecase) Do(param) (err error) {
    defer (){
        // 這裡可以把 error log 或是把err加上 Do 和 pararm 資訊 傳上去，或是前面有其他人提到的把err放進ctx也可以
    }

這樣 log 只能知道 call Do 的時候發生了甚麼，但是無法知道 call DoSomethingA 時用了甚麼 parameter，發生了甚麼。

    err = repo.DoSomethingA()
    if err != nil{
        return
    }
    err = repo.DoSomethingA()
    if err != nil{
        return
    }
}```
以上主要是想減少log的程式碼散落各處
順便看大家覺得這樣會不會有啥漏洞

還有一個問題是：有些 function 出 error 是我們期待有可能會發生並且不影響實際執行的，那這時候的 log level 應該要使用較低層級的 level ，或是特別嚴重的 error 時要提高 log level ，但要這樣做的話可能又需要在 defer 裡額外的邏輯判斷。

PichuChen · 2021-02-06T11:22:13Z

Log Level 的部分一開始是參考 RFC 5424 進行設計的。

Markogoodman · 2021-02-06T11:51:21Z

疑惑為什麼同一個 function 出現的 error 會差滿多這件事，與此相關想問要怎麼區分 error 發生在上面的 DoSomethingA 還是下面的 DoSomthingA ？

我打錯了 "一個func下面呼叫的不同func" 所以應該是 DoSomethingA 和 DoSomethingB
預期他們會處理不同的事情，發生 error 時傳回來的 error 也不太一樣
我是比較少遇到一個func底下會重複呼叫同一個func的情況

這樣 log 只能知道 call Do 的時候發生了甚麼，但是無法知道 call DoSomethingA 時用了甚麼 parameter，發生了甚麼。

如同這邊的 defer 會把 func param 的相關資訊包起來
DoSomethingA 和 DoSomethingB 也可以把相關 param 資訊包起來傳回來

還有一個問題是：有些 function 出 error 是我們期待有可能會發生並且不影響實際執行的，那這時候的 log level 應該要使用較低層級的 level ，或是特別嚴重的 error 時要提高 log level ，但要這樣做的話可能又需要在 defer 裡額外的邏輯判斷。

那我覺得這個像是 warning，可以多打沒關係
通常如果遇到有err的情況但可以繼續執行
應該會做類似下面的事情?

if err!=nil{
    // 處理 ex: log.Warning 
    err = nil
    // no return
}
繼續執行

或是定義個

type MyError struct {
    Level 
}

defer 時候就可以用個統一個func來處理了

asymptoter · 2021-02-06T13:08:07Z

我是比較少遇到一個func底下會重複呼叫同一個func的情況

Golang 中應該會滿常碰到 function 中會重複呼叫同一個 function 的情形，尤其是當系統變的龐大且複雜的時候就更容易產生以下的關係：

A -> B -> C
└ -> D -> C

這時候看到有一個 log 顯示 C function 出錯，但是無法直接知道到底是 B call 的時候 C 出錯了，還是 D call 的時候 C 出錯了，就必須要使用 log 中的資訊去慢慢還原，更不用說以下情形：

func Do(params...) (res..., error) {
    for _, param := range params {
        if err := DoSomething(param); err != nil {
            // handle error
        }
    }
}

這時候就只能祈禱 DoSomething 不是 external package 或是 golang origin package 中的 function 了。

如同這邊的 defer 會把 func param 的相關資訊包起來
DoSomethingA 和 DoSomethingB 也可以把相關 param 資訊包起來傳回來

這有一個很大的問題上面也提到了，當 DoSomethingA 和/或 DoSomethingB 是使用外部的 function 的時候就無法保證這件事，既然如此，這樣是不是應該要在出錯的當下記錄起足以 debug 的資訊會比較好？

Markogoodman · 2021-02-06T16:25:37Z

Golang 中應該會滿常碰到 function 中會重複呼叫同一個 function 的情形，尤其是當系統變的龐大且複雜的時候就更容易產生以下的關係：
A -> B -> C
└ -> D -> C

同意常常會有這種情況
所以只要在C裡面加入

func C(param) err{
   defer func(){
      addInfoToErr(err, "C", param) // 把 func name 和 param 資訊加入 err 然後 return
   }
}

就可以避免
B 和 D 裡面都出現這種東西

err = C(param)
if err !=nil{
    addInfoToErr(err, "C",  param) // 可以避免掉很多重複的 log code
    return
}

如果B與D也都有把自己的資訊包起來傳回給A
到最後A看到的err內容物就會有呼叫B(D)與相關param 以及呼叫C與相關param

其實我提的 defer 只是想把那些的紀錄資訊搬到被呼叫的 function 裡面
如果呼叫者每次呼叫 function 都需要自己去紀錄資訊一次，那應該會出現滿多重複的

func Do(params...) (res..., error) {
    for _, param := range params {
        if err := DoSomething(param); err != nil {
             // handle error
        }
    }
}
這時候就只能祈禱 DoSomething 不是 external package 或是 golang origin package 中的 function 了。

前面那個 defer 只能處理內部function沒錯

當使用的 DoSomething 是外部 function
再多加入資訊就好了

   for _, param := range params {
      if err := DoSomething(param); err != nil {
         addInfoToErr(err, param)

       }
   }

但如果真的在很多不同function都會呼叫到DoSomething ，且遇到每個 DoSomething 都必需要記錄當下 param and err 資訊

那我認為把 DoSomething 外面再包一層自己的 func 也是能處理掉重複code的情況

func DoSomethingWithErrInfo() err{
    defer.....
    err = DoSomething()
    addInfoToErr(err...)
}

總結一下我只是想避免太多重複的 log 資訊記錄，把 log 資訊記錄這個行為搬到該function內而已XD

KScaesar · 2021-02-09T14:44:55Z

目前在code裡面還看到滿多log的指令的，感覺可以減少一些
我覺得只要request進來後log一下相關資訊一次就好例如urlpath method ip 之類的
之後如果發生error的話再 log 即可(覺得可以只在 usecase 層 log 就好)

同意只需要做一次 log
我看書的建議是說
其他層有錯誤, 應該往上傳不應該 log
log 在系統的邊界處執行就可以

系統邊界處
是用例層(use case) 或用戶交互層(分發層? 驅動層?)

用例層的物件
可能被多種分發層複用
http 驅動 use case 或 grpc 驅動 use case

因為我自己實作 ddd 整潔架構的時候
只有一種驅動層 http rest api 的形式
所以我 log 都集中在驅動層

我不推薦 error 時只在 usercase log 一次的作法，原因是 route 層也有可能在解析 request 的 parameter 或是 body 時出錯。

我自己定義系統核心
是把用例層之內的稱為核心

如果需要支援多種驅動方式(grpc cli ...)
我覺得用例層統一輸出 log 也是不錯

route 層也有可能在解析 request 的 parameter 或是 body 時出錯
我這個認為是 input 就失敗
還沒進入核心
或許可以把還沒進入核心的 log 跟進入核心的 log 分別看待??

還有建議可以用 defer 來處理
就不必在每個 if err != nil 的地方都各自弄

這個也不推薦，defer 的話無法知道實際發生錯誤的行數。

用 defer 來處理 err 或 log
我覺得是寫的時候舒服
看起來整潔
但查 bug 的時候, 反而不那麼直覺

現在很多編輯器都支援
若 log 輸出有路徑的格式
直接點下去, 就跳轉到 log 或 err 發生的地方

用 defer 來寫, 就需要另外看 log 的訊息
才知道錯誤發生的準確位置
無法直接跳轉得知

KScaesar · 2021-02-09T14:51:14Z

可考慮

https://github.com/spf13/jwalterweatherman
https://github.com/sirupsen/logrus

https://github.com/rs/zerolog

KScaesar · 2021-02-09T15:06:04Z

Golang 中應該會滿常碰到 function 中會重複呼叫同一個 function 的情形，尤其是當系統變的龐大且複雜的時候就更容易產生以下的關係：
A -> B -> C
└ -> D -> C
這有一個很大的問題上面也提到了，當 DoSomethingA 和/或 DoSomethingB 是使用外部的 function 的時候就無法保證這件事，既然如此，這樣是不是應該要在出錯的當下記錄起足以 debug 的資訊會比較好？

這應該所有語言都會遇到重複呼叫的問題
跟 go 的關係應該不大?

照我前面所說
只在系統邊界處輸出 log
儘量不要同時做了 err 往上傳, 又輸出 err log

依照這例子
B C D 應該回傳 err , A L 輸出 log

並且在 err 內寫出詳細的訊息
跟是否為外部套件的函數, 應該沒有什麼關係
處理 err 的時候, 把訊息補上就是了

老實說標準庫的 error pkg 功能很弱
可能無法達成詳細的 err 訊息輸出

err 套件
最常見的應該還是
https://pkg.go.dev/github.com/pkg/errors
但總覺得缺了一些功能

我自己想去使用的有
https://github.com/cockroachdb/errors
這個感覺功能最齊
但好像很複雜xd
還沒研究哪些是最必要日常會使用到的

https://github.com/hashicorp/go-multierror

Markogoodman · 2021-02-11T08:09:59Z

現在很多編輯器都支援
若 log 輸出有路徑的格式
直接點下去, 就跳轉到 log 或 err 發生的地方

從來沒用過這種東西ＸＤ
聽起來滿方便的
原本會使用 defer 來做就是想避免 caller 每次呼叫同一個 func 都要主動包一次 err 資訊，會增加重複的code
如果下面那些err package可以更簡便地做到應該也不錯(但我也沒用過就是了)
這樣看來也要討論error package的選擇了（？

PichuChen · 2021-07-15T07:41:38Z

這個 ISSUE 目前還有在更新嗎？不然兩週後要把他先關掉了喔？

tanyeun mentioned this issue Feb 4, 2021

[建議] logger增加debug level的功能 #29

Closed

mkfsn mentioned this issue Feb 17, 2021

[建議] 把 interface 宣告移到使用者處，並移除非必要的 interface #71

Open

karta0807913 mentioned this issue Aug 21, 2021

加入 log level #272

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

如何設計/使用 logger? #21

如何設計/使用 logger? #21

mkfsn commented Jan 30, 2021

itsarbit commented Jan 30, 2021

asymptoter commented Jan 30, 2021

maxjkfc commented Feb 4, 2021

PichuChen commented Feb 4, 2021

sageofcross commented Feb 4, 2021

maxjkfc commented Feb 4, 2021

Markogoodman commented Feb 5, 2021 •

edited

Loading

asymptoter commented Feb 5, 2021

chhsiao1981 commented Feb 6, 2021

Markogoodman commented Feb 6, 2021 •

edited

Loading

asymptoter commented Feb 6, 2021

PichuChen commented Feb 6, 2021

Markogoodman commented Feb 6, 2021 •

edited

Loading

asymptoter commented Feb 6, 2021 •

edited

Loading

Markogoodman commented Feb 6, 2021 •

edited

Loading

KScaesar commented Feb 9, 2021 •

edited

Loading

KScaesar commented Feb 9, 2021

KScaesar commented Feb 9, 2021 •

edited

Loading

Markogoodman commented Feb 11, 2021 •

edited

Loading

PichuChen commented Jul 15, 2021

如何設計/使用 logger? #21

如何設計/使用 logger? #21

Comments

mkfsn commented Jan 30, 2021

itsarbit commented Jan 30, 2021

asymptoter commented Jan 30, 2021

maxjkfc commented Feb 4, 2021

PichuChen commented Feb 4, 2021

sageofcross commented Feb 4, 2021

maxjkfc commented Feb 4, 2021

Markogoodman commented Feb 5, 2021 • edited Loading

asymptoter commented Feb 5, 2021

chhsiao1981 commented Feb 6, 2021

Markogoodman commented Feb 6, 2021 • edited Loading

asymptoter commented Feb 6, 2021

PichuChen commented Feb 6, 2021

Markogoodman commented Feb 6, 2021 • edited Loading

asymptoter commented Feb 6, 2021 • edited Loading

Markogoodman commented Feb 6, 2021 • edited Loading

KScaesar commented Feb 9, 2021 • edited Loading

KScaesar commented Feb 9, 2021

KScaesar commented Feb 9, 2021 • edited Loading

Markogoodman commented Feb 11, 2021 • edited Loading

PichuChen commented Jul 15, 2021

Markogoodman commented Feb 5, 2021 •

edited

Loading

Markogoodman commented Feb 6, 2021 •

edited

Loading

Markogoodman commented Feb 6, 2021 •

edited

Loading

asymptoter commented Feb 6, 2021 •

edited

Loading

Markogoodman commented Feb 6, 2021 •

edited

Loading

KScaesar commented Feb 9, 2021 •

edited

Loading

KScaesar commented Feb 9, 2021 •

edited

Loading

Markogoodman commented Feb 11, 2021 •

edited

Loading