log4go源码分析(一)

本文涉及的产品
日志服务 SLS,月写入数据量 50GB 1个月
简介: log4go源码分析(一)

之前记录的一篇日志博文log4go源码分析只是占了个坑,没写具体内容。


一直想研究分享几个开源项目提高提高,但由于工作忙一直没时间。今天把业余时间总结的log4go源码分析的第一篇记录下来。


Java中有个log4j,是著名的开源日志框架,可以控制日志信息输送的目的地是控制台、文件、GUI组件,甚至是套接口服务器等。我们也可以控制每一条日志的输出格式,通过定义每一条日志信息的级别,我们能够更加细致地控制日志的生成过程。最令人感兴趣的就是这些可以通过一个配置文件来灵活地进行配置,而不需要修改应用的代码。甚至可以灵活的做到对产生的日志文件进行按大小或者按日期进行日志切割。


log4go是go语言中的开源的日志框架,功能差不多。


go中的log4go大致可分为几个模块,如配置模块,可通过json或xml进行配置。


输出日志到控制台模块,输出日志到socket模块,输出日志到文件模块等。


学习别人框架源码的好处之一就是可以看下别人的结构和框架,对语法的灵活运用等。比如把接口运用的很合理,在应用层接口不变的情况下仍然可以做到扩展和灵活的配置,有那种敏捷开发的思想。通过对优秀源码的学习来进一步提高自己。


log4go中对不同输出对应几个Logger,虽然是用go语言实现的,但面向对象的思想一点不弱。


NewConsoleLogger,


NewFileLogWriter,


NewSocketLogWriter,


格式化日志记录、写入文件、转储日志等,都会消耗 CPU 的时间,并可能因为错误处理而阻塞主线程。但日志系统仅仅是一个辅助功能,所以,保证主线程的高效运行是首先要达到的设计要求。异步写入是可行的方案之一。


log4go 的特点之一是异步写入。


log4go 的特点之二自扩展日志接口。


log4go 的特点之三支持通过json或xml配置文件对日志进行配置。


log4go的异步写入利用了go上的协程,据此也可以看出go语言的优秀之处。协程比java中的线程好用多了。因为它有个很好的同步机制,chan。Go 语言中的通道(channel)是一种特殊的类型。在任何时候,同时只能有一个 goroutine 访问通道进行发送和获取数据。goroutine 间通过通道就可以通信。通道像一个传送带或者队列,总是遵循先入先出(First In First Out)的规则,保证收发数据的顺序。


这里先分析一下NewConsoleLogger,输出日志到控制台的。


核心的地方以下几处:


/****** LogRecord ******/
// A LogRecord contains all of the pertinent information for each message
type LogRecord struct {
  Level    Level     // The log level
  Created  time.Time // The time at which the log message was created (nanoseconds)
  Source   string    // The message source
  Message  string    // The log message
  Category string    // The log group
}


定义了一个结构体,把写日志比喻成写一条一条的记录。一条日志里的信息有级别,日期时间,Source源代码的信息,Message欲输出的日志内容,Category日志的分类。


FormatLogRecord,对日志的格式化,由于对日志的一系列格式化也是比较占cpu的,这里的处理就很巧妙,不是每次都去格式化,而是每间隔一定周期才处理一次,且使用了bytes.NewBuffer,先写入到buffer,最后一块儿写入管道。管道里是LogRecord


//
func changeDttmFormat(format string, rec *LogRecord) []byte {
  formatByte := []byte(format)
  r := regexp.MustCompile("\\%D\\{(.*?)\\}")
  i := 0
  formatByte = r.ReplaceAllFunc(formatByte, func(s []byte) []byte {
    if i < 2 {
      i++
      str := string(s)
      str = strings.Replace(str, "%D", "", -1)
      str = strings.Replace(str, "{", "", -1)
      str = strings.Replace(str, "}", "", -1)
      return []byte(rec.Created.Format(str))
    }
    return s
  })
  return formatByte
}
type formatCacheType struct {
  LastUpdateSeconds    int64
  shortTime, shortDate string
  longTime, longDate   string
}
var formatCache = &formatCacheType{}
// Known format codes:
// %T - Time (15:04:05 MST)
// %t - Time (15:04)
// %D - Date (2006/01/02)
// %d - Date (01/02/06)
// %L - Level (FNST, FINE, DEBG, TRAC, WARN, EROR, CRIT)
// %S - Source
// %M - Message
// Ignores unknown formats
// Recommended: "[%D %T] [%L] (%S) %M"
func FormatLogRecord(format string, rec *LogRecord) string {
  if rec == nil {
    return "<nil>"
  }
  if len(format) == 0 {
    return ""
  }
  out := bytes.NewBuffer(make([]byte, 0, 64))
  secs := rec.Created.UnixNano() / 1e9
  cache := *formatCache
  if cache.LastUpdateSeconds != secs {
    month, day, year := rec.Created.Month(), rec.Created.Day(), rec.Created.Year()
    hour, minute, second := rec.Created.Hour(), rec.Created.Minute(), rec.Created.Second()
    zone, _ := rec.Created.Zone()
    updated := &formatCacheType{
      LastUpdateSeconds: secs,
      shortTime:         fmt.Sprintf("%02d:%02d", hour, minute),
      shortDate:         fmt.Sprintf("%02d/%02d/%02d", day, month, year%100),
      longTime:          fmt.Sprintf("%02d:%02d:%02d %s", hour, minute, second, zone),
      longDate:          fmt.Sprintf("%04d/%02d/%02d", year, month, day),
    }
    cache = *updated
    formatCache = updated
  }
  //custom format datetime pattern %D{2006-01-02T15:04:05}
  formatByte := changeDttmFormat(format, rec)
  // Split the string into pieces by % signs
  pieces := bytes.Split(formatByte, []byte{'%'})
  // Iterate over the pieces, replacing known formats
  for i, piece := range pieces {
    if i > 0 && len(piece) > 0 {
      switch piece[0] {
      case 'T':
        out.WriteString(cache.longTime)
      case 't':
        out.WriteString(cache.shortTime)
      case 'D':
        out.WriteString(cache.longDate)
      case 'd':
        out.WriteString(cache.shortDate)
      case 'L':
        out.WriteString(levelStrings[rec.Level])
      case 'S':
        out.WriteString(rec.Source)
      case 's':
        slice := strings.Split(rec.Source, "/")
        out.WriteString(slice[len(slice)-1])
      case 'M':
        out.WriteString(rec.Message)
      case 'C':
        // if len(rec.Category) == 0 {
        //  rec.Category = "DEFAULT"
        // }
        // out.WriteString(rec.Category)
        if len(rec.Category) == 0 {
          out.WriteString("DEFAULT")
        } else {
          out.WriteString(rec.Category)
        }
      }
      if len(piece) > 1 {
        out.Write(piece[1:])
      }
    } else if len(piece) > 0 {
      out.Write(piece)
    }
  }
  out.WriteByte('\n')
  return out.String()
}


有一个协程,专门负责异步写入日志记录到控制台,go consoleWriter.run(stdout)


func (c *ConsoleLogWriter) run(out io.Writer) {
  for rec := range c.w {
    fmt.Fprint(out, FormatLogRecord(c.format, rec))
  }
}
// This creates a new ConsoleLogWriter
func NewConsoleLogWriter() *ConsoleLogWriter {
  consoleWriter := &ConsoleLogWriter{
    format: "[%T %D] [%C] [%L] (%S) %M",
    w:      make(chan *LogRecord, LogBufferLength),
  }
  go consoleWriter.run(stdout)
  return consoleWriter
}


接口的使用,接口的强大之处体现出来了,ConsoleLogWriter实现了这个接口。


/****** LogWriter ******/
// This is an interface for anything that should be able to write logs
type LogWriter interface {
  // This will be called to log a LogRecord message.
  LogWrite(rec *LogRecord)
  // This should clean up anything lingering about the LogWriter, as it is called before
  // the LogWriter is removed.  LogWrite should not be called after Close.
  Close()
}
// This is the ConsoleLogWriter's output method.  This will block if the output
// buffer is full.
func (c *ConsoleLogWriter) LogWrite(rec *LogRecord) {
  c.w <- rec
}
// Close stops the logger from sending messages to standard output.  Attempts to
// send log messages to this logger after a Close have undefined behavior.
func (c *ConsoleLogWriter) Close() {
  close(c.w)
  time.Sleep(50 * time.Millisecond) // Try to give console I/O time to complete
}


通过Filter对日志进行归类。分类输出。


/****** Logger ******/
// A Filter represents the log level below which no log records are written to
// the associated LogWriter.
type Filter struct {
  Level Level
  LogWriter
  Category string
}
// A Logger represents a collection of Filters through which log messages are
// written.
type Logger map[string]*Filter
// Create a new logger with a "stdout" filter configured to send log messages at
// or above lvl to standard output.
func NewDefaultLogger(lvl Level) Logger {
  return Logger{
    "stdout": &Filter{lvl, NewConsoleLogWriter(), "DEFAULT"},
  }
}


如何获取当前日志所在的行号和代码文件的?通过runtime.Caller(2),runtime.FuncForPC(pc).Name()获取。


/******* Logging *******/
// Send a formatted log message internally
func (log Logger) intLogf(lvl Level, format string, args ...interface{}) {
  skip := true
  // Determine if any logging will be done
  for _, filt := range log {
    if lvl >= filt.Level {
      skip = false
      break
    }
  }
  if skip {
    return
  }
  // Determine caller func
  pc, _, lineno, ok := runtime.Caller(2)
  src := ""
  if ok {
    src = fmt.Sprintf("%s:%d", runtime.FuncForPC(pc).Name(), lineno)
  }
  msg := format
  if len(args) > 0 {
    msg = fmt.Sprintf(format, args...)
  }
  // Make the log record
  rec := &LogRecord{
    Level:   lvl,
    Created: time.Now(),
    Source:  src,
    Message: msg,
  }
  // Dispatch the logs
  for _, filt := range log {
    if lvl < filt.Level {
      continue
    }
    filt.LogWrite(rec)
  }
}


为了跟系统的log日志接口兼容,再做一层包装,如:


// Wrapper for (*Logger).Info
func Info(arg0 interface{}, args ...interface{}) {
  const (
    lvl = INFO
  )
  switch first := arg0.(type) {
  case string:
    // Use the string as a format string
    Global.intLogf(lvl, first, args...)
  case func() string:
    // Log the closure (no other arguments used)
    Global.intLogc(lvl, first)
  default:
    // Build a format string so that it will be similar to Sprint
    Global.intLogf(lvl, fmt.Sprint(arg0)+strings.Repeat(" %v", len(args)), args...)
  }
}


总结以下最小实现在一个文件里总共300行代码左右。如下:


package main
import (
  "bytes"
  "fmt"
  "io"
  "os"
  "regexp"
  "runtime"
  "strings"
  "time"
)
/****** Constants ******/
// These are the integer logging levels used by the logger
type Level int
const (
  FINEST Level = iota
  FINE
  DEBUG
  TRACE
  INFO
  WARNING
  ERROR
  CRITICAL
)
// Logging level strings
var (
  levelStrings = [...]string{"FNST", "FINE", "DEBG", "TRAC", "INFO", "WARN", "EROR", "CRIT"}
)
/****** Variables ******/
var (
  // LogBufferLength specifies how many log messages a particular log4go
  // logger can buffer at a time before writing them.
  LogBufferLength = 1
)
/****** LogRecord ******/
// A LogRecord contains all of the pertinent information for each message
type LogRecord struct {
  Level    Level     // The log level
  Created  time.Time // The time at which the log message was created (nanoseconds)
  Source   string    // The message source
  Message  string    // The log message
  Category string    // The log group
}
/****** LogWriter ******/
// This is an interface for anything that should be able to write logs
type LogWriter interface {
  // This will be called to log a LogRecord message.
  LogWrite(rec *LogRecord)
  // This should clean up anything lingering about the LogWriter, as it is called before
  // the LogWriter is removed.  LogWrite should not be called after Close.
  Close()
}
/****** Logger ******/
// A Filter represents the log level below which no log records are written to
// the associated LogWriter.
type Filter struct {
  Level Level
  LogWriter
  Category string
}
// A Logger represents a collection of Filters through which log messages are
// written.
type Logger map[string]*Filter
// This is the standard writer that prints to standard output.
type ConsoleLogWriter struct {
  format string
  w      chan *LogRecord
}
var stdout io.Writer = os.Stdout
// This creates a new ConsoleLogWriter
func NewConsoleLogWriter() *ConsoleLogWriter {
  consoleWriter := &ConsoleLogWriter{
    format: "[%T %D] [%C] [%L] (%S) %M",
    w:      make(chan *LogRecord, LogBufferLength),
  }
  go consoleWriter.run(stdout)
  return consoleWriter
}
func (c *ConsoleLogWriter) SetFormat(format string) {
  c.format = format
}
func (c *ConsoleLogWriter) run(out io.Writer) {
  for rec := range c.w {
    fmt.Fprint(out, FormatLogRecord(c.format, rec))
  }
}
// This is the ConsoleLogWriter's output method.  This will block if the output
// buffer is full.
func (c *ConsoleLogWriter) LogWrite(rec *LogRecord) {
  c.w <- rec
}
// Close stops the logger from sending messages to standard output.  Attempts to
// send log messages to this logger after a Close have undefined behavior.
func (c *ConsoleLogWriter) Close() {
  close(c.w)
  time.Sleep(50 * time.Millisecond) // Try to give console I/O time to complete
}
// Create a new logger with a "stdout" filter configured to send log messages at
// or above lvl to standard output.
func NewDefaultLogger(lvl Level) Logger {
  return Logger{
    "stdout": &Filter{lvl, NewConsoleLogWriter(), "DEFAULT"},
  }
}
//
func changeDttmFormat(format string, rec *LogRecord) []byte {
  formatByte := []byte(format)
  r := regexp.MustCompile("\\%D\\{(.*?)\\}")
  i := 0
  formatByte = r.ReplaceAllFunc(formatByte, func(s []byte) []byte {
    if i < 2 {
      i++
      str := string(s)
      str = strings.Replace(str, "%D", "", -1)
      str = strings.Replace(str, "{", "", -1)
      str = strings.Replace(str, "}", "", -1)
      return []byte(rec.Created.Format(str))
    }
    return s
  })
  return formatByte
}
type formatCacheType struct {
  LastUpdateSeconds    int64
  shortTime, shortDate string
  longTime, longDate   string
}
var formatCache = &formatCacheType{}
// Known format codes:
// %T - Time (15:04:05 MST)
// %t - Time (15:04)
// %D - Date (2006/01/02)
// %d - Date (01/02/06)
// %L - Level (FNST, FINE, DEBG, TRAC, WARN, EROR, CRIT)
// %S - Source
// %M - Message
// Ignores unknown formats
// Recommended: "[%D %T] [%L] (%S) %M"
func FormatLogRecord(format string, rec *LogRecord) string {
  if rec == nil {
    return "<nil>"
  }
  if len(format) == 0 {
    return ""
  }
  out := bytes.NewBuffer(make([]byte, 0, 64))
  secs := rec.Created.UnixNano() / 1e9
  cache := *formatCache
  if cache.LastUpdateSeconds != secs {
    month, day, year := rec.Created.Month(), rec.Created.Day(), rec.Created.Year()
    hour, minute, second := rec.Created.Hour(), rec.Created.Minute(), rec.Created.Second()
    zone, _ := rec.Created.Zone()
    updated := &formatCacheType{
      LastUpdateSeconds: secs,
      shortTime:         fmt.Sprintf("%02d:%02d", hour, minute),
      shortDate:         fmt.Sprintf("%02d/%02d/%02d", day, month, year%100),
      longTime:          fmt.Sprintf("%02d:%02d:%02d %s", hour, minute, second, zone),
      longDate:          fmt.Sprintf("%04d/%02d/%02d", year, month, day),
    }
    cache = *updated
    formatCache = updated
  }
  //custom format datetime pattern %D{2006-01-02T15:04:05}
  formatByte := changeDttmFormat(format, rec)
  // Split the string into pieces by % signs
  pieces := bytes.Split(formatByte, []byte{'%'})
  // Iterate over the pieces, replacing known formats
  for i, piece := range pieces {
    if i > 0 && len(piece) > 0 {
      switch piece[0] {
      case 'T':
        out.WriteString(cache.longTime)
      case 't':
        out.WriteString(cache.shortTime)
      case 'D':
        out.WriteString(cache.longDate)
      case 'd':
        out.WriteString(cache.shortDate)
      case 'L':
        out.WriteString(levelStrings[rec.Level])
      case 'S':
        out.WriteString(rec.Source)
      case 's':
        slice := strings.Split(rec.Source, "/")
        out.WriteString(slice[len(slice)-1])
      case 'M':
        out.WriteString(rec.Message)
      case 'C':
        // if len(rec.Category) == 0 {
        //  rec.Category = "DEFAULT"
        // }
        // out.WriteString(rec.Category)
        if len(rec.Category) == 0 {
          out.WriteString("DEFAULT")
        } else {
          out.WriteString(rec.Category)
        }
      }
      if len(piece) > 1 {
        out.Write(piece[1:])
      }
    } else if len(piece) > 0 {
      out.Write(piece)
    }
  }
  out.WriteByte('\n')
  return out.String()
}
var (
  Global Logger
)
/******* Logging *******/
// Send a formatted log message internally
func (log Logger) intLogf(lvl Level, format string, args ...interface{}) {
  skip := true
  // Determine if any logging will be done
  for _, filt := range log {
    if lvl >= filt.Level {
      skip = false
      break
    }
  }
  if skip {
    return
  }
  // Determine caller func
  pc, _, lineno, ok := runtime.Caller(2)
  src := ""
  if ok {
    src = fmt.Sprintf("%s:%d", runtime.FuncForPC(pc).Name(), lineno)
  }
  msg := format
  if len(args) > 0 {
    msg = fmt.Sprintf(format, args...)
  }
  // Make the log record
  rec := &LogRecord{
    Level:   lvl,
    Created: time.Now(),
    Source:  src,
    Message: msg,
  }
  // Dispatch the logs
  for _, filt := range log {
    if lvl < filt.Level {
      continue
    }
    filt.LogWrite(rec)
  }
}
// Send a closure log message internally
func (log Logger) intLogc(lvl Level, closure func() string) {
  skip := true
  // Determine if any logging will be done
  for _, filt := range log {
    if lvl >= filt.Level {
      skip = false
      break
    }
  }
  if skip {
    return
  }
  // Determine caller func
  pc, _, lineno, ok := runtime.Caller(2)
  src := ""
  if ok {
    src = fmt.Sprintf("%s:%d", runtime.FuncForPC(pc).Name(), lineno)
  }
  // Make the log record
  rec := &LogRecord{
    Level:   lvl,
    Created: time.Now(),
    Source:  src,
    Message: closure(),
  }
  // Dispatch the logs
  for _, filt := range log {
    if lvl < filt.Level {
      continue
    }
    filt.LogWrite(rec)
  }
}
// Wrapper for (*Logger).Info
func Info(arg0 interface{}, args ...interface{}) {
  const (
    lvl = INFO
  )
  switch first := arg0.(type) {
  case string:
    // Use the string as a format string
    Global.intLogf(lvl, first, args...)
  case func() string:
    // Log the closure (no other arguments used)
    Global.intLogc(lvl, first)
  default:
    // Build a format string so that it will be similar to Sprint
    Global.intLogf(lvl, fmt.Sprint(arg0)+strings.Repeat(" %v", len(args)), args...)
  }
}
// Utility for debug log messages
// When given a string as the first argument, this behaves like Logf but with the DEBUG log level (e.g. the first argument is interpreted as a format for the latter arguments)
// When given a closure of type func()string, this logs the string returned by the closure iff it will be logged.  The closure runs at most one time.
// When given anything else, the log message will be each of the arguments formatted with %v and separated by spaces (ala Sprint).
// Wrapper for (*Logger).Debug
func Debug(arg0 interface{}, args ...interface{}) {
  const (
    lvl = DEBUG
  )
  switch first := arg0.(type) {
  case string:
    // Use the string as a format string
    Global.intLogf(lvl, first, args...)
  case func() string:
    // Log the closure (no other arguments used)
    Global.intLogc(lvl, first)
  default:
    // Build a format string so that it will be similar to Sprint
    Global.intLogf(lvl, fmt.Sprint(arg0)+strings.Repeat(" %v", len(args)), args...)
  }
}
func main() {
  Global = NewDefaultLogger(FINE)
  // original log4go test
  Info("nomal info test 1...")
  Debug("nomal debug test 1...")
  Info("nomal info test2 ...")
  Debug("nomal debug test2 ...")
  Info("nomal info test 3...")
  Debug("nomal debug test3 ...")
  Info("nomal info test4 ...")
  Debug("nomal debug test4 ...")
  Info("nomal info test 5...")
  Debug("nomal debug test ...")
  fmt.Println("over,press any key to exit ")
  name := ""
  fmt.Scanln(&name)
}


相关实践学习
日志服务之使用Nginx模式采集日志
本文介绍如何通过日志服务控制台创建Nginx模式的Logtail配置快速采集Nginx日志并进行多维度分析。
相关文章
|
JavaScript Go
雪崩利器 hystrix-go 源码分析
阅读源码的过程,就像是在像武侠小说里阅读武功秘籍一样,分析高手的一招一式,提炼出精髓,来增强自己的内力。 之前的帖子说了一下微服务的雪崩效应和常见的解决方案,太水,没有上代码怎么叫解决方案。github上有很多开源的库来解决雪崩问题,比较出名的是Netflix的开源库hystrix。
1091 0
|
Kubernetes 容器
Kubernetes Client-go Informer 源码分析
几乎所有的Controller manager 和CRD Controller 都会使用Client-go 的Informer 函数,这样通过Watch 或者Get List 可以获取对应的Object,下面我们从源码分析角度来看一下Client go Informer 的机制。
4577 0
|
网络协议 Go Memcache
go gomemcache包源码分析
go gomemcache包源码分析
11201 0
|
分布式数据库 Go Hbase
|
5天前
|
存储 JSON 监控
Viper,一个Go语言配置管理神器!
Viper 是一个功能强大的 Go 语言配置管理库,支持从多种来源读取配置,包括文件、环境变量、远程配置中心等。本文详细介绍了 Viper 的核心特性和使用方法,包括从本地 YAML 文件和 Consul 远程配置中心读取配置的示例。Viper 的多来源配置、动态配置和轻松集成特性使其成为管理复杂应用配置的理想选择。
23 2
|
3天前
|
Go 索引
go语言中的循环语句
【11月更文挑战第4天】
11 2
|
3天前
|
Go C++
go语言中的条件语句
【11月更文挑战第4天】
14 2