本分析基于 go 1.23 版本
简介
log 库是 go 官方提供一个简单的日志记录标准库,是由 Russ Cox 操刀编写的,并由 Joe Tsai 在后续版本做了对锁的优化,大幅度提高了运行效率。总代码 500 余行,核心代码 200 余行,实现的简洁优雅,很值得新手学习。
使用
package main
import (
"bytes"
"fmt"
"log"
)
func main() {
var (
buf bytes.Buffer
logger = log.New(&buf, "[Prefix]", log.Lshortfile)
)
logger.Print("Hello!")
// [Prefix]main.go:15: Hello!
fmt.Print(&buf)
}
首先需要新建一个 logger,需要传入三个参数,日志输出位置(一个 io.Writer
对象)、日志前缀(字符串,每次打印日志都会跟随输出)、日志属性(定义好的常量)。创建好就可以调用方法进行日志输出。
日志属性可选项如下:
属性 | 说明 |
---|---|
Ldate | 当前时区的日期,格式:2009/01/23 |
Ltime | 当前时区的时间,格式:01:23:23 |
Lmicroseconds | 当前时区的时间,格式:01:23:23.123123,精确到微妙 |
Llongfile | 全文件名和行号,格式:/a/b/c/d.go:23 |
Lshortfile | 当前文件名和行号,格式:d.go:23,会覆盖 Llongfile |
LUTC | 使用 UTC 而非本地时区,推荐日志全部使用 UTC 时间 |
Lmsgprefix | 将 prefix 内容从行首移动到日志内容前面 |
LstdFlags | 标准 logger 对象的初始值(等于:Ldate|Ltime ) |
这些属性都是预定义好的常量,可以直接通过 |
运算符组合使用。且这些属性的格式和顺序都无法更改,当 Llongfile 或者 Lshortfile 被设置时 header 中会多个冒号。
logger 结构体支持 9 种方法来输出日志内容:
函数名 | 作用 | 使用示例 |
---|---|---|
打印日志 | log.Print(“Print”) | |
Printf | 打印格式化日志 | log.Printf(“Printf: %s”, “print”) |
Println | 打印日志并换行 | log.Println(“Println”) |
Panic | 打印日志后执行 panic(s)(s 为日志内容) | log.Panic(“Panic”) |
Panicf | 打印格式化日志后执行 panic(s) | log.Panicf(“Panicf: %s”, “panic”) |
Panicln | 打印日志并换行后执行 panic(s) | log.Panicln(“Panicln”) |
Fatal | 打印日志后执行 os.Exit(1) | log.Fatal(“Fatal”) |
Fatalf | 打印格式化日志后执行 os.Exit(1) | log.Fatalf(“Fatalf: %s”, “fatal”) |
Fatalln | 打印日志并换行后执行 os.Exit(1) | log.Panicln(“Panicln”) |
Panic 系列和 Fatal 系列主要的区别如下:
panic(s)
:用于处理不可恢复的错误或意外情况,会执行defer
语句,允许通过recover
恢复。适合在需要捕获并处理异常的情况下使用。os.Exit(1)
:用于立即退出程序,不执行defer
语句,也不能通过recover
恢复。适合在程序需要立即终止时使用。
这些函数使用的时候不需要额外添加换行符,log 包会在检测到最后一个字符不是换行符时自动补充一个换行符。
源码分析
位的使用
const (
Ldate = 1 << iota
Ltime
Lmicroseconds
Llongfile
Lshortfile
LUTC
Lmsgprefix
LstdFlags = Ldate | Ltime
)
是如何只提供一个配置项 flags 就可以支持如此多的配置呢?秘密就在位的运算上,这个 int 的每一位都代表了一个不同的配置,通过简单的与运算就可以得知是否设置了该项配置。
if flag&Lmsgprefix == 0 {
*buf = append(*buf, prefix...)
}
整型的 ASCII 编码
// Cheap integer to fixed-width decimal ASCII. Give a negative width to avoid zero-padding.
func itoa(buf *[]byte, i int, wid int) {
// Assemble decimal in reverse order.
var b [20]byte
bp := len(b) - 1
for i >= 10 || wid > 1 {
wid--
q := i / 10
b[bp] = byte('0' + i - q*10)
bp--
i = q
}
// i < 10
b[bp] = byte('0' + i)
*buf = append(*buf, b[bp:]...)
}
这段代码实现了一个将整数转换为定宽(Fixed-width)的十进制ASCII字符串的函数,并将结果追加到一个字节切片中。
itoa
函数接受三个参数:
buf *[]byte
:指向一个字节切片的指针,用来存储转换后的结果。i int
:要转换的整数。wid int
:指定的宽度。如果为负数,表示不要进行零填充。b
是一个长度为 20 的字节数组,用来临时存储转换过程中生成的字符。bp
是一个指针,初始化为数组b
的最后一个位置,表示当前存放字符的位置。(在Go语言中,int
类型的长度通常与平台有关。在64位系统上,int
通常是64位的。这意味着最大值为9223372036854775807
(19位数字),最小值为-9223372036854775808
(负号加19位数字)。即使考虑到负号,20个字节足够容纳任何可能的整数值。)
通过循环的计算,将传入的 i 值,转换成了 ASCII 值,同时保证了宽度是 wid。
atomic
type Logger struct {
outMu sync.Mutex
out io.Writer // destination for output
prefix atomic.Pointer[string] // prefix on each line to identify the logger (but see Lmsgprefix)
flag atomic.Int32 // properties
isDiscard atomic.Bool
}
在之前的版本中,对 Logger 结构体中的字段修改都需要获取锁(当时还没有这些 atomic 类型,只能用锁),在这里都优化成了使用 atomic 类型。只在写入日志时使用锁。
func TestAtomic(t *testing.T) {
var flag atomic.Int32
val := int32(1024)
flag.Store(val)
assert.Equal(t, val, flag.Load())
var prefix atomic.Pointer[string]
str := "p"
prefix.Store(&str)
assert.Equal(t, str, *prefix.Load())
}
sync.Pool
var bufferPool = sync.Pool{New: func() any { return new([]byte) }}
func getBuffer() *[]byte {
p := bufferPool.Get().(*[]byte)
*p = (*p)[:0]
return p
}
func putBuffer(p *[]byte) {
if cap(*p) > 64<<10 {
*p = nil
}
bufferPool.Put(p)
}
- 通过复用指针,
sync.Pool
可以更快地提供切片,而不需要每次都进行内存分配和回收。 - 这有助于提高程序的性能,特别是在需要频繁创建和销毁字节切片的场景中。
- 当分配的字节切片容量大于 64 KB 时就不回收了,直接释放
runtime.Caller
// Caller reports file and line number information about function invocations on
// the calling goroutine's stack. The argument skip is the number of stack frames
// to ascend, with 0 identifying the caller of Caller. (For historical reasons the
// meaning of skip differs between Caller and [Callers].) The return values report the
// program counter, file name, and line number within the file of the corresponding
// call. The boolean ok is false if it was not possible to recover the information.
func Caller(skip int) (pc uintptr, file string, line int, ok bool) {
rpc := make([]uintptr, 1)
n := callers(skip+1, rpc[:])
if n < 1 {
return
}
frame, _ := CallersFrames(rpc).Next()
return frame.PC, frame.File, frame.Line, frame.PC != 0
}
- skip:
skip
参数指定了需要跳过的栈帧数量。skip=0
时,表示当前调用runtime.Caller
的那一行代码,skip=1
表示调用者的调用者,以此类推。
- pc:第一个返回值,表示程序计数器(PC)。
- file:调用的源文件的文件名。
- line:调用的源文件的行号。
- ok:布尔值,表示是否成功获取信息。
PC(Program Counter):runtime.Caller
的第一个返回值是程序计数器,它是一个 uintptr
类型的值,表示调用者在代码中的位置。这个值可以传递给 runtime.FuncForPC
函数来获取与该程序计数器关联的函数信息,比如函数名、文件名和行号等。
func TestCaller(t *testing.T) {
// Skip 0 means we're getting the Caller inside exampleFunction itself
pc, file, line, ok := runtime.Caller(0)
if !ok {
fmt.Println("runtime.Caller failed")
return
}
// Retrieve the function details using the program counter
fn := runtime.FuncForPC(pc)
functionName := fn.Name()
t.Logf("Called from function: %s\n", functionName)
t.Logf("In file: %s\n", file)
t.Logf("At line: %d\n", line)
}
函数式编程(闭包)
func (l *Logger) Printf(format string, v ...any) {
l.output(0, 2, func(b []byte) []byte {
return fmt.Appendf(b, format, v...)
})
}
是如何将生成的 header 放在输出的内容之前的,这里传入了一个 appendOutput func([]byte) []byte
类型的函数,在调用的时候将 header 传入即可,返回值就是生成好格式的结果。
延伸阅读
- https://pkg.go.dev/log
- https://cs.opensource.google/go/go/+/refs/tags/go1.23.0:src/log/log.go
- 深入探究 Go log 标准库
附录
package log
import (
"fmt"
"io"
"runtime"
"sync"
"sync/atomic"
"time"
)
// These flags define which text to prefix to each log entry generated by the [Logger].
// Bits are or'ed together to control what's printed.
// With the exception of the Lmsgprefix flag, there is no
// control over the order they appear (the order listed here)
// or the format they present (as described in the comments).
// The prefix is followed by a colon only when Llongfile or Lshortfile
// is specified.
// For example, flags Ldate | Ltime (or LstdFlags) produce,
//
// 2009/01/23 01:23:23 message
//
// while flags Ldate | Ltime | Lmicroseconds | Llongfile produce,
//
// 2009/01/23 01:23:23.123123 /a/b/c/d.go:23: message
const (
Ldate = 1 << iota
Ltime
Lmicroseconds
Llongfile
Lshortfile
LUTC
Lmsgprefix
LstdFlags = Ldate | Ltime
)
// A Logger represents an active logging object that generates lines of
// output to an [io.Writer]. Each logging operation makes a single call to
// the Writer's Write method. A Logger can be used simultaneously from
// multiple goroutines; it guarantees to serialize access to the Writer.
type Logger struct {
outMu sync.Mutex
out io.Writer // destination for output
prefix atomic.Pointer[string] // prefix on each line to identify the logger (but see Lmsgprefix)
flag atomic.Int32 // properties
isDiscard atomic.Bool
}
// New creates a new [Logger]. The out variable sets the
// destination to which log data will be written.
// The prefix appears at the beginning of each generated log line, or
// after the log header if the [Lmsgprefix] flag is provided.
// The flag argument defines the logging properties.
func New(out io.Writer, prefix string, flag int) *Logger {
l := new(Logger)
l.SetOutput(out)
l.SetPrefix(prefix)
l.SetFlags(flag)
return l
}
// SetOutput sets the output destination for the logger.
func (l *Logger) SetOutput(w io.Writer) {
l.outMu.Lock()
defer l.outMu.Unlock()
l.out = w
l.isDiscard.Store(w == io.Discard)
}
// SetPrefix sets the output prefix for the logger.
func (l *Logger) SetPrefix(prefix string) {
l.prefix.Store(&prefix)
}
// SetFlags sets the output flags for the logger.
// The flag bits are [Ldate], [Ltime], and so on.
func (l *Logger) SetFlags(flag int) {
l.flag.Store(int32(flag))
}
// Writer returns the output destination for the logger.
func (l *Logger) Writer() io.Writer {
l.outMu.Lock()
defer l.outMu.Unlock()
return l.out
}
// Prefix returns the output prefix for the logger.
func (l *Logger) Prefix() string {
if p := l.prefix.Load(); p != nil {
return *p
}
return ""
}
// Flags returns the output flags for the logger.
// The flag bits are [Ldate], [Ltime], and so on.
func (l *Logger) Flags() int {
return int(l.flag.Load())
}
// Cheap integer to fixed-width decimal ASCII. Give a negative width to avoid zero-padding.
func itoa(buf *[]byte, i int, wid int) {
// Assemble decimal in reverse order.
var b [20]byte
bp := len(b) - 1
for i >= 10 || wid > 1 {
wid--
q := i / 10
b[bp] = byte('0' + i - q*10)
bp--
i = q
}
// i < 10
b[bp] = byte('0' + i)
*buf = append(*buf, b[bp:]...)
}
// formatHeader writes log header to buf in following order:
// - l.prefix (if it's not blank and Lmsgprefix is unset),
// - date and/or time (if corresponding flags are provided),
// - file and line number (if corresponding flags are provided),
// - l.prefix (if it's not blank and Lmsgprefix is set).
func formatHeader(buf *[]byte, t time.Time, prefix string, flag int, file string, line int) {
if flag&Lmsgprefix == 0 {
*buf = append(*buf, prefix...)
}
if flag&(Ldate|Ltime|Lmicroseconds) != 0 {
if flag&LUTC != 0 {
t = t.UTC()
}
if flag&Ldate != 0 {
year, month, day := t.Date()
itoa(buf, year, 4)
*buf = append(*buf, '/')
itoa(buf, int(month), 2)
*buf = append(*buf, '/')
itoa(buf, day, 2)
*buf = append(*buf, ' ')
}
if flag&(Ltime|Lmicroseconds) != 0 {
hour, min, sec := t.Clock()
itoa(buf, hour, 2)
*buf = append(*buf, ':')
itoa(buf, min, 2)
*buf = append(*buf, ':')
itoa(buf, sec, 2)
if flag&Lmicroseconds != 0 {
*buf = append(*buf, '.')
itoa(buf, t.Nanosecond()/1e3, 6)
}
*buf = append(*buf, ' ')
}
}
if flag&(Lshortfile|Llongfile) != 0 {
if flag&Lshortfile != 0 {
short := file
for i := len(file) - 1; i > 0; i-- {
if file[i] == '/' {
short = file[i+1:]
break
}
}
file = short
}
*buf = append(*buf, file...)
*buf = append(*buf, ':')
itoa(buf, line, -1)
*buf = append(*buf, ": "...)
}
if flag&Lmsgprefix != 0 {
*buf = append(*buf, prefix...)
}
}
var bufferPool = sync.Pool{New: func() any { return new([]byte) }}
func getBuffer() *[]byte {
p := bufferPool.Get().(*[]byte)
*p = (*p)[:0]
return p
}
func putBuffer(p *[]byte) {
if cap(*p) > 64<<10 {
*p = nil
}
bufferPool.Put(p)
}
// output can take either a calldepth or a pc to get source line information.
// It uses the pc if it is non-zero.
func (l *Logger) output(pc uintptr, calldepth int, appendOutput func([]byte) []byte) error {
if l.isDiscard.Load() {
return nil
}
now := time.Now() // get this early.
// Load prefix and flag once so that their value is consistent within
// this call regardless of any concurrent changes to their value.
prefix := l.Prefix()
flag := l.Flags()
var file string
var line int
if flag&(Lshortfile|Llongfile) != 0 {
if pc == 0 {
var ok bool
_, file, line, ok = runtime.Caller(calldepth)
if !ok {
file = "???"
line = 0
}
} else {
fs := runtime.CallersFrames([]uintptr{pc})
f, _ := fs.Next()
file = f.File
if file == "" {
file = "???"
}
line = f.Line
}
}
buf := getBuffer()
defer putBuffer(buf)
formatHeader(buf, now, prefix, flag, file, line)
*buf = appendOutput(*buf)
if len(*buf) == 0 || (*buf)[len(*buf)-1] != '\n' {
*buf = append(*buf, '\n')
}
l.outMu.Lock()
defer l.outMu.Unlock()
_, err := l.out.Write(*buf)
return err
}
// Printf calls l.Output to print to the logger.
// Arguments are handled in the manner of [fmt.Printf].
func (l *Logger) Printf(format string, v ...any) {
l.output(0, 2, func(b []byte) []byte {
return fmt.Appendf(b, format, v...)
})
}
![知识共享许可协议](https://image-1252109614.cos.ap-beijing.myqcloud.com/img/20210508215939.png)
本作品采用知识共享署名-非商业性使用-相同方式共享 4.0 国际许可协议进行许可。