• Go实现日志2——支持结构化和hook

    代码保存在：https://github.com/liwook/Go-projects/tree/main/log/sulogV2​​​​​​​

    1.日志结构化

    日志记录的事件以结构化格式(键值对，或通常是 JSON)表示，随后可以通过编程方式对其进行解析，便于对日志进行监控、警报、审计等其他形式的分析。

    结构化的格式例子。

    time=2023-10-08T21:09:03.912+08:00 level=INFO msg=TextHandler 姓名=陈

    那这里就要回顾下(entry).log方法。

    1. func (e *Entry) log(level Level, msg string) {
    2. 	e.Message = msg,e.Time = time.Now(),e.Level = level
    3.  
    4. 	e.File, e.Line, e.Func = file, line, runtime.FuncForPC(pc).Name()
    5. 	e.Func = e.Func[strings.LastIndex(e.Func, "/")+1:]
    6.  
    7. 	e.write()
    8. }
    9.  
    10. func (e *Entry) write() {
    11. 	e.logger.mu.Lock()
    12. 	defer e.logger.mu.Unlock()
    13. 	e.logger.opt.formatter.Format(e)
    14. 	e.logger.opt.output.Write(e.Buffer.Bytes())
    15. }

    在e.write()中，其主要是两步：按照规定的格式化数据后，把信息存在e.Buffer中；然后经由e.write()写入。重点在格式化数据那步，所以我们要看e.format方法。

    那就回到Formatter接口。而JSON类型的是已经结构化的，重点来看看TEXT文本格式的。

    文本格式结构化

    在formatter.go文件中添加些常量：

    1. //formatter.go
    2. const (
    3. 	defaultTimestampFormat = time.RFC3339
    4. 	KeyMsg                 = "msg"
    5. 	KeyLevel               = "level"
    6. 	KeyTime                = "time"
    7. 	KeyFunc                = "func"
    8. 	KeyFile                = "file"
    9. )

     在formatter_text.go中进行修改添加：

    1. //formatter_text.go
    2. // 格式是： 时间 日志等级 文件:所在行号 函数名称 日志内容
    3. func (f *TextFormatter) Format(e *Entry) error {
    4. 	if !f.DisableTimestamp {
    5. 		if f.TimestampFormat == "" {
    6. 			f.TimestampFormat = time.RFC3339
    7. 		}
    8. 		f.appendKeyValue(e.Buffer, KeyTime, e.Time.Format(f.TimestampFormat))
    9. 	}
    10. 	f.appendKeyValue(e.Buffer, KeyLevel, LevelName[e.Level])    //添加日志等级
    11.  
    12. 	if !e.logger.opt.disableCaller {
    13. 		if e.File != "" {
    14. 			short := e.File
    15. 			for i := len(e.File) - 1; i > 0; i-- {
    16. 				if e.File[i] == '/' {
    17. 					short = e.File[i+1:]
    18. 					break
    19. 				}
    20. 			}
    21.             //添加函数名和文件名
    22. 			f.appendKeyValue(e.Buffer, KeyFunc, short)
    23. 			f.appendKeyValue(e.Buffer, KeyFile, e.File+":"+strconv.Itoa(e.Line))
    24. 		}
    25. 	}
    26.  
    27. 	f.appendKeyValue(e.Buffer, KeyMsg, e.Message)
    28.  
    29. 	e.Buffer.WriteString("\n")
    30. 	return nil
    31. }
    32.  
    33. //上一节的写法，没有结构化的
    34. func (f *TextFormatter) Format(e *Entry) error {
    35. 	if !f.DisableTimestamp {
    36. 		if f.TimestampFormat == "" {
    37. 			f.TimestampFormat = time.RFC3339
    38. 		}
    39. 		e.Buffer.WriteString(fmt.Sprintf("%s %s", e.Time.Format(f.TimestampFormat), LevelNameMapping[e.Level]))
    40. 	} else {
    41. 		e.Buffer.WriteString(LevelNameMapping[e.Level])
    42. 	}
    43. 	if e.File != "" {
    44. 		short := e.File
    45. 		for i := len(e.File) - 1; i > 0; i-- {
    46. 			if e.File[i] == '/' {
    47. 				short = e.File[i+1:]
    48. 				break
    49. 			}
    50. 		}
    51.  
    52. 		e.Buffer.WriteString(fmt.Sprintf(" %s:%d %s", short, e.Line, e.Func))
    53. 	}
    54. 	e.Buffer.WriteString(" ")
    55.  
    56. 	e.Buffer.WriteString(e.Message)
    57. 	e.Buffer.WriteByte('\n')
    58.  
    59. 	return nil
    60. }

     新的Format方法也好理解，主要是增添了调用appendKeyValue方法，该方法是进行键值对格式书写的。

    1. func (f *TextFormatter) appendKeyValue(b *bytes.Buffer, key string, value any) {
    2. 	if b.Len() > 0 {
    3. 		b.WriteByte(' ')
    4. 	}
    5. 	b.WriteString(key)
    6. 	b.WriteByte('=')
    7. 	f.appendValue(b, value)
    8. }
    9.  
    10. func (f *TextFormatter) appendValue(b *bytes.Buffer, value any) {
    11. 	stringVal, ok := value.(string)
    12. 	if !ok {
    13. 		stringVal = fmt.Sprint(value)
    14. 		b.WriteString(stringVal)
    15. 	} else {
    16. 		b.WriteString(fmt.Sprintf("%q", stringVal)) //这样就是加""符号的
    17. 	}
    18. }

    到现在TEXT文本格式的也可以进行结构化输出了。

    1. sulog.Info("hello info")
    2.  
    3. //输出结果
    4. time="2024-01-29T11:45:33+08:00" level="INFO" func="main.go" file="D:/code/gWork/log/sulogV2/cmd/main.go:42" msg="hello info"

    增添WithField和WithFields

    做到这一步还不够，还有这种需求，想额外输出name="li" age=13这种的。就不单单是输出msg=...。

    level="INFO" func="main.go" file="D:/code/gWork/log/sulogV2/cmd/main.go:42" msg="hello info" name="li" age=13

    代码使用例子：两个方法WithField和WithFields

    1. 	sulog.WithField("age", "11").Info("ok withField")
    2. 	sulog.WithFields(sulog.Fields{
    3. 		"name":  "li",
    4. 		"age":   32,
    5. 	}).Info("ok withFields")

    调用WithField后，还可以继续调用，说明其返回值应该是logger或者entry。

    在logger.go中添加这两个方法，该方法返回值是*Entry。这两个方法都需要从entryPool中获取一个entry。

    1. //optins.go
    2. // Fields type, used to pass to `WithFields`.
    3. type Fields map[string]any
    4.  
    5. //logger.go
    6. func (l *logger) WithField(key string, value any) *Entry {
    7. 	entry := l.entry()
    8. 	defer l.releaseEntry(entry)
    9. 	return entry.WithField(key, value)
    10. }
    11.  
    12. func (l *logger) WithFields(fields Fields) *Entry {
    13. 	entry := l.entry()
    14. 	defer l.releaseEntry(entry)
    15. 	return entry.WithFields(fields)
    16. }
    17.  
    18.  
    19. //全局的 std
    20. func WithField(key string, value any) *Entry {
    21. 	return std.WithField(key, value)
    22. }
    23.  
    24. func WithFields(fields Fields) *Entry {
    25. 	return std.WithFields(fields)
    26. }

     那接着就到了结构体Entry中了。(Entry).WithField也是调用WithFields。

    而在WithFields方法的参数中，fields的键值对的值是any类型，所以需要用到reflcect来进行类型判别筛选。WithFields返回值是*Entry，该方法中是返回了一个新Entry，所以需要拷贝*logger,data属性。

    1. //entry.go
    2. type Entry struct {
    3.     //该结构体其他的没有改变，只是DataMap不再使用，改为使用Data,基本是一样的意思的
    4. 	// DataMap map[string]any //为了日志是json格式使用的
    5. 	Data    Fields //保存WithField中的数据
    6.     .................
    7. }
    8.  
    9. // Add a single field to the Entry.
    10. func (entry *Entry) WithField(key string, value any) *Entry {
    11. 	return entry.WithFields(Fields{key: value})
    12. }
    13.  
    14. // Add a map of fields to the Entry.
    15. func (entry *Entry) WithFields(fields Fields) *Entry {
    16. 	data := make(Fields, len(entry.Data)+len(fields))
    17. 	//为了可以这样使用sulog.WithField("name","li").WithField("addr","zhong").Info(1)
    18. 	for k, v := range entry.Data {
    19. 		data[k] = v
    20. 	}
    21.  
    22. 	for k, v := range fields {
    23. 		isErrField := false
    24. 		if t := reflect.TypeOf(v); t != nil {
    25. 			//如果value类型是函数类型，是不符合要求的
    26. 			if t.Kind() == reflect.Func || (t.Kind() == reflect.Pointer && t.Elem().Kind() == reflect.Func) {
    27. 				isErrField = true
    28. 			}
    29. 		}
    30.  
    31. 		if isErrField {
    32. 			tmp := fmt.Sprintf("can not add field %q", k)
    33. 			fmt.Println(tmp)
    34. 		} else {
    35. 			data[k] = v
    36. 		}
    37. 	}
    38.  
    39. 	return &Entry{logger: entry.logger, Data: data}
    40. }

    WithFields返回*Entry后可以继续打印日志，说明Entry也需要实现Debug这些方法。

    1. // entry打印方法
    2. func (e *Entry) Debug(args ...any) {
    3. 	e.Log(3, DebugLevel, args...)        //3是调用 runtime.Caller() 时，传入的栈深度
    4. }
    5.  
    6. // 自定义格式
    7. func (e *Entry) Debugf(format string, args ...any) {
    8. 	e.Logf(3, DebugLevel, format, args...)
    9. }

    在sulog.WithField("age", "11").Info("ok withField")代码中，WithField后会进行releseEntry，即entry.Buffer也被重置了。那要获取到之前的Buffer的话，那就需要在WithFields中拷贝entry.Buffer(或者重新new)，这可能会浪费些性能。

    1. func (entry *Entry) WithFields(fields Fields) *Entry {
    2. 	data := make(Fields, len(entry.Data)+len(fields))
    3.     .........................
    4.  
    5. 	//return &Entry{logger: entry.logger, Data: data}
    6.     return &Entry{logger: entry.logger, Data: data,Buffer:entry.Buffer}//拷贝Buffer
    7. }

     再看回到使用entry.Buffer的地方(entry).log方法中，这里是没有对entry.Buffer进行new的，直接使用的话，是会出问题的。

    所以我们也可以仿照entryPool那样，也使用sync.Pool类型来做一个Buffer池。

    在logger中添加sync.Pool类型的Buffer池

    在logger结构体中添加如下

    1. type logger struct {
    2.     .............
    3. 	entryPool  *sync.Pool
    4. 	bufferPool *sync.Pool    //添加Buffer池
    5. }
    6.  
    7. func New(opts ...Option) *logger {
    8. 	logger := &logger{opt: initOptions(opts...), Hooks: make(LevelHooks)}
    9. 	logger.entryPool = &sync.Pool{New: func() any { return entry(logger) }}
    10.     //初始化bufferPool
    11. 	logger.bufferPool = &sync.Pool{New: func() any { return new(bytes.Buffer) }}
    12. 	return logger
    13. }
    14.  
    15. //entry.go
    16. //创建entry  的方法就有了改变，不再需要new(bytes.Buffer)
    17. func entry(logger *logger) *Entry {
    18. 	return &Entry{
    19. 		logger: logger,
    20. 		// Buffer:  new(bytes.Buffer),
    21. 		// DataMap: make(map[string]any, 5)
    22. 		Data: make(map[string]any, 5),
    23. 	}
    24. }

     之后修改(Entry).log方法，在其中通过bufferPool获取Buffer。

    1. func (e *Entry) log(depth int, level Level, msg string) {
    2. 	e.Time = time.Now()
    3. 	e.Level = level
    4. 	e.Message = msg
    5.  
    6. 	if !e.logger.opt.disableCaller {
    7. 		if pc, file, line, ok := runtime.Caller(depth); !ok {
    8. 			e.File = "???"
    9. 			e.Func = "???"
    10. 		} else {
    11. 			e.File, e.Line, e.Func = file, line, runtime.FuncForPC(pc).Name()
    12. 			e.Func = e.Func[strings.LastIndex(e.Func, "/")+1:]
    13. 		}
    14. 	}
    15.  
    16. 	bufPool := e.logger.bufferPool
    17. 	buffer := bufPool.Get().(*bytes.Buffer)//获取buffer
    18. 	e.Buffer = buffer
    19. 	defer func() {    //使用完后，放回bufferPool池中
    20. 		e.Buffer = nil
    21. 		buffer.Reset()
    22. 		bufPool.Put(buffer)
    23. 	}()
    24.  
    25. 	e.write()
    26. }

    而且这样写，使用sulog.Info("info")也正常了，因为创建entry时候是没有new(bytes.Buffer)。

    接着来看看测试例子：

    1. sulog.WithField("name", "11").Info("ok withField")
    2. sulog.WithFields(sulog.Fields{
    3. 		"name": "li",
    4. 		"age":  32,
    5. 	}).Info("ok withFields")
    6.  
    7. //打印结果
    8. time="2024-01-29T13:52:42+08:00" level="INFO" func="main.go" file="D:/code/gWork/log/sulogV2/cmd/main.go:46" msg="ok withField" name="11"
    9. time="2024-01-29T13:52:42+08:00" level="INFO" func="main.go" file="D:/code/gWork/log/sulogV2/cmd/main.go:50" msg="ok withFields" age=32 name="li"

    区分WithField中的键"level" 和 sulog.Info()中的"level"

    到这里是基本完成了，但还是可能会有问题，比如：

    sulog.WithField("level", "debug").Info("ok withField")

    这种日志等级应该是info,但是在WithField中level写到是debug,那就会有冲突了。时间和函数名那些要是也这样写的话，也会有冲突的。那该怎么做呢，那就做个区分，只要是在WithField中的，一致使用field.*来表示，level就用field.level来表示。

    在formatter.go文件中添加如下代码：

    该函数功能是查看WithField中要是有"level","file"这些，就把key修改成"fields.levle"等等。

    1. //data是WithField方法中的数据
    2. func prefixFieldClashes(data Fields) {
    3. 	for k, v := range data {
    4. 		switch k {
    5. 		case KeyMsg:
    6. 			data["fields."+KeyMsg] = v
    7. 			delete(data, KeyMsg)
    8. 		case KeyLevel:
    9. 			data["fields."+KeyLevel] = v
    10. 			delete(data, KeyLevel)
    11. 		case KeyFunc:
    12. 			data["fields."+KeyFunc] = v
    13. 			delete(data, KeyFunc)
    14. 		case KeyTime:
    15. 			data["fields."+KeyTime] = v
    16. 			delete(data, KeyTime)
    17. 		case KeyFile:
    18. 			data["fields."+KeyFile] = v
    19. 			delete(data, KeyFile)
    20. 		}
    21. 	}
    22. }

    那么在JSON格式和TEXT格式的Format方法中使用。

    1. func (f *JsonFormatter) Format(e *Entry) error {
    2. 	data := make(Fields, len(e.Data)+5)
    3. 	prefixFieldClashes(e.Data)
    4. 	for k, v := range e.Data {
    5. 		data[k] = v
    6. 	}
    7. 	if !f.DisableTimestamp {
    8. 		if f.TimestampFormat == "" {
    9. 			f.TimestampFormat = time.RFC3339
    10. 		}
    11. 		data[KeyTime] = e.Time.Format(f.TimestampFormat)
    12. 	}
    13.  
    14. 	data[KeyLevel] = LevelName[e.Level]
    15.  
    16. 	if e.File != "" {
    17. 		data[KeyFile] = e.File + ":" + strconv.Itoa(e.Line)
    18. 		data[KeyFunc] = e.Func
    19. 	}
    20.  
    21. 	data[KeyMsg] = e.Message
    22.  
    23. 	return sonic.ConfigDefault.NewEncoder(e.Buffer).Encode(data)
    24. }
    25.  
    26.  
    27. //TEXT文本格式的
    28. func (f *TextFormatter) Format(e *Entry) error {
    29. 	prefixFieldClashes(e.Data)
    30.  
    31. 	if !f.DisableTimestamp {
    32. 	    ................
    33. 	}
    34.     ...............
    35. 	f.appendKeyValue(e.Buffer, KeyMsg, e.Message)
    36. 	//加上WithField()中的
    37. 	for k, v := range e.Data {
    38. 		f.appendKeyValue(e.Buffer, k, v)
    39. 	}
    40.  
    41. 	e.Buffer.WriteString("\n")
    42. 	return nil
    43. }

    来看看测试结果

    1. 	sulog.SetOptions(sulog.WithDisableCaller(true))
    2. 	sulog.SetOptions(sulog.WithFormatter(&sulog.JsonFormatter{DisableTimestamp: true}))
    3. 	sulog.WithFields(sulog.Fields{
    4. 		"level": "info",
    5. 		"name":  "lihai",
    6. 		"msg":   "this field message",
    7. 	}).Info("ok withField")
    8.  
    9. //打印结果
    10. {"fields.msg":"this field message","name":"lihai","fields.level":"info","level":"INFO","msg":"我们ok withField"}

    在使用该日志时，鼓励用sulog.WithFields(log.Fields{}).Infof() 这种方式替代sulog.Infof("Failed to send event %s to topic %s")， 也就是不是用 %s，%d 这种方式格式化，而是直接传入变量 event，topic 给 log.Fields ，这样就显得结构化日志输出，很人性化美观。

    2.支持hook

    钩子（Hooks），可以理解成函数，可以让我们在日志输出前或输出后进行一些额外的处理。常见的使用场景包括发送邮件、写入数据库、上传到云端等。

    一个日志，是有很多日志等级的，那就可能需要筛选出符合条件的等级才能触发hook。

    在logger结构体中添加变量Hooks：

    即是可以添加多个日志等级的hook,一个日志等级可以有多个hook。

    1. //新添加hooks.go文件，添加该类型
    2. type LevelHooks map[Level][]Hook
    3.  
    4.  
    5. //logger.go
    6. type logger struct {
    7.     ...................
    8. 	Hooks LevelHooks //多个日志等级的多个hook
    9. }

    定义Hook

    其肯定是有对应的可执行的日志等级列表和执行的函数这两个的。

    给用户使用，那我们可以定义成接口，命名为Hook。

    用户实现Hook接口即可。

    1. type Hook interface {
    2. 	Levels() []Level
    3. 	Fire(*Entry) error
    4. }

    所以在Hook中用户需要做的就是在Fire方法中定义想如何操作这一条日志的方法，在Levels方法中定义想展示的日志级别。

    给LevelHooks添加方法

    那肯定是有添加hook（Add）和执行所有hook(Fire)的方法。

    1. func (hooks LevelHooks) Add(hook Hook) {
    2. 	for _, level := range hook.Levels() {
    3. 		hooks[level] = append(hooks[level], hook)
    4. 	}
    5. }
    6.  
    7. //执行日志等级列表中全部hook
    8. func (hooks LevelHooks) Fire(level Level, entry *Entry) error {
    9. 	for _, hook := range hooks[level] {
    10. 		if err := hook.Fire(entry); err != nil {
    11. 			return err
    12. 		}
    13. 	}
    14.  
    15. 	return nil
    16. }

    那在logger结构体中增加AddHook方法。

    1. // 添加hook
    2. func (l *logger) AddHook(hook Hook) {
    3.     //用锁，保证了执行hook时候就不能添加hook
    4. 	l.mu.Lock()
    5. 	defer l.mu.Unlock()
    6. 	l.Hooks.Add(hook)
    7. }
    8.  
    9. func AddHook(hook Hook) {
    10. 	std.AddHook(hook)
    11. }

    很明显，(LevelHooks).Add在(logger).AddHook中调用了，而Fire没有使用，那这样的话，钩子函数就没有能执行。

    执行hook

    那其应该是在哪被调用呢？应该在（Entry).log中。

    1. func (e *Entry) log(depth int, level Level, msg string) {
    2.     ............
    3. 	if !e.logger.opt.disableCaller {
    4.         .....................
    5. 	}
    6.  
    7. 	e.fireHooks()    //执行hook, 就是在这添加这句
    8.  
    9. 	bufPool := e.logger.bufferPool
    10.     ...............
    11.  
    12. 	e.write()
    13. }
    14.  
    15. //这种写法不好，执行hook时候一直霸占锁，不妥
    16. func (entry *Entry) fireHooks() {
    17. 	entry.logger.mu.Lock()
    18. 	err := entry.logger.Hooks.Fire(entry.Level, entry)
    19. 	if err != nil {
    20. 		fmt.Fprintf(os.Stderr, "Failed to fire hook: %v\n", err)
    21. 	}
    22. 	entry.logger.mu.Unlock()
    23. }

    一般是很容易想到上面的fireHooks的实现，但这种实现不好，要是hook是比较耗时的操作，那就会一直霸占锁，可以会引起阻塞。

    解决办法：我们可以用个临时变量把所有的hook拷贝过来，之后就可以释放锁，然后就可以执行hook。这样就不会长时间霸占锁。

    1. func (entry *Entry) fireHooks() {
    2. 	var tmpHooks LevelHooks    //临时变量
    3. 	entry.logger.mu.Lock()
    4. 	tmpHooks = make(LevelHooks, len(entry.logger.Hooks))
    5. 	//进行拷贝
    6. 	for k, v := range entry.logger.Hooks {
    7. 		tmpHooks[k] = v
    8. 	}
    9. 	entry.logger.mu.Unlock()
    10.  
    11. 	err := tmpHooks.Fire(entry.Level, entry) //执行hook
    12. 	if err != nil {
    13. 		fmt.Fprintf(os.Stderr, "Failed to fire hook: %v\n", err)
    14. 	}
    15. }

    测试：

    实现Hook接口。

    1. type hook struct{}
    2.  
    3. func (h *hook) Levels() []sulog.Level {
    4. 	// return sulog.AllLevels
    5. 	return []sulog.Level{sulog.InfoLevel, sulog.DebugLevel}//只有info和debug两种等级
    6. }
    7.  
    8. func (h *hook) Fire(entry *sulog.Entry) error {
    9. 	fmt.Printf("send emial. this is a hook func:%v\n", entry.Data)
    10. 	return nil
    11. }
    12.  
    13. func main() {
    14. 	sulog.SetOptions(sulog.WithDisableCaller(true))
    15. 	sulog.SetOptions(sulog.WithFormatter(&sulog.TextFormatter{DisableTimestamp: true}))
    16. 	sulog.AddHook(&hook{})
    17. 	sulog.WithField("name", "11").Info("ok withField")
    18. 	fmt.Println()
    19. 	sulog.WithField("country", "China").Error("ok withField")
    20. }

    效果：

    1. this is a hook func:map[name:11]
    2. level="INFO" msg="ok withField" name="11"
    3.  
    4. level="ERROR" msg="ok withField" country="China"

  • 相关阅读:
    Angular 中的路由
    想进入游戏建模行业，这4点必须了解
    【vscode远程开发】使用内网穿透实现在公网环境下远程访问
    新零售六大模式，你学会了吗？
    Linux 虚拟机内挂载 iso 文件
    LQ0134 最大降雨量【中位数】
    SpingMvc入门
    Centos7 bash：jps：Command not found....
    【LeetCode】No.78. Subsets -- Java Version
    DOM 文档对象模型(Document Object Model), W3C 组织推荐的处理可扩展标记语言的标准编程接口。
  • 原文地址：https://blog.csdn.net/m0_57408211/article/details/135906524