之前记录的一篇日志博文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，输出日志到控制台的。
核心的地方以下几处：
代码语言：javascript复制/****** 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
代码语言：javascript复制//
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("d:d", hour, minute),
shortDate: fmt.Sprintf("d/d/d", day, month, year0),
longTime: fmt.Sprintf("d:d:d %s", hour, minute, second, zone),
longDate: fmt.Sprintf("d/d/d", 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)
代码语言：javascript复制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实现了这个接口。
代码语言：javascript复制/****** 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对日志进行归类。分类输出。
代码语言：javascript复制/****** 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()获取。
代码语言：javascript复制/******* 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日志接口兼容，再做一层包装，如：
代码语言：javascript复制// 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行代码左右。如下：
代码语言：javascript复制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("d:d", hour, minute),
shortDate: fmt.Sprintf("d/d/d", day, month, year0),
longTime: fmt.Sprintf("d:d:d %s", hour, minute, second, zone),
longDate: fmt.Sprintf("d/d/d", 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)
}
