docker中logrus与日志原理(二)信息打印

最新推荐文章于 2024-09-09 02:48:43 发布

温暖的电波

最新推荐文章于 2024-09-09 02:48:43 发布

阅读量2.1k

点赞数

分类专栏：容器

本文链接：https://blog.csdn.net/wennuanddianbo/article/details/79027500

版权

容器专栏收录该内容

18 篇文章 0 订阅

订阅专栏

在docker中logrus与日志原理(一)中曾经分析到容器的打印输出和日志功能的基础骨架都是在Entry.log()函数中来完成；而这个Entry.log()又包含两个部分：1) 通过log driver的钩子函数来记录日志；2) 将信息输出到终端。

这一章主要分析logrus在Entry.log()中是如何将信息打印到终端输出的。我们仍然看回到Entry.log()函数，并精减掉此处没有用到的代码：

// This function is not declared with a pointer value because otherwise
// race conditions will occur when using multiple goroutines
func (entry Entry) log(level Level, msg string) {
	//......
	if err := entry.Logger.Hooks.Fire(level, &entry); err != nil {
		entry.Logger.mu.Lock()
		fmt.Fprintf(os.Stderr, "Failed to fire hook: %v\n", err)
		entry.Logger.mu.Unlock()
	}

	reader, err := entry.Reader()
	//......
	_, err = io.Copy(entry.Logger.Out, reader)
	//......
}

这里将信息输出到终端由两个步骤构成：

1) 由entry.Reader()来生成一个Reader类型的值reader，也就是终端信息的提供对象;

2) 将Reader中的信息拷贝(写入)到接收者entry.Logger.Out。这是由io.Copy(entry.Logger.Out, reader)实现的。

下面我们就来仔细分析一下这些流程的细节。

一、准备信息提供者Reader

函数io.Copy(Write, Reader)有两个参数，第一个是Write接口类型，是信息的接收的"目标";第二个是Reader类型，是信息发出的"源"。这里先看看Reader是如何创建的。

Reader是golang标准io包提供的一个接口，golang/src/pkg/io/io.go:

type Reader interface {
	Read(p []byte) (n int, err error)
}

所有实现了Read(p []byte) (n int, err error)方法的类型都是Reader。在这里通过entry.Reader()来创建一个Reader对象，在vendor/src/github.com/Sirupsen/logrus/entry.go文件中实现：

// Returns a reader for the entry, which is a proxy to the formatter.
func (entry *Entry) Reader() (*bytes.Buffer, error) {
	serialized, err := entry.Logger.Formatter.Format(entry)		//serialized为[]bytes结构
	return bytes.NewBuffer(serialized), err				//返回一个butes.Buffer结构指针		
}

Entry.Reader()做两件事情：1) 通过etnry.Logger.Formatter.Format(entry)将打印信息格式化，并转换为[]butes类型；2) 根据格式化信息创建一个bytes.Buffer变量，bytes.Buffer实现了Reader接口。

其中bytes.NewBuffer()这个函数由golang标准包bytes实现：golang/src/pkg/bytes/buffer.go:

//bytes.NewBuffer(serialized)返回一个Buffer结构对象
func NewBuffer(buf []byte) *Buffer { return &Buffer{buf: buf}

即最终这个信息提供者Reader最终是bytes.NewBuffer()创建的一个Buffer对象引用。

二、entry.Logger.Out

上面已经了解到，io.Copy()函数的"源"已通过bytes.NewBuffer创建好，而io.Copy()的"目标"entry.Logger.Out是什么么？最终我们将看到这个entry.Logger.Out实际上就是os.Stderr，即代表类unix系统标准错误输出设备的一个变量。这样一来io.Copy()的"源"、"目标"都有了，接着io.Copy(entry.Logger.Out, reader)函数就水到渠成的完成了将信息从"Reader"到"Writer"的写入。

2.1 entry.Logger.Out的来龙去脉

我们上面就已经说到entry.Logger.Out就是标准错误输出设备，但是怎么来的似乎是一个迷，接下来我们就来解开它。

要解开entry.Logger.Out我们需要再理一理整个logrus.Infof()输出打印信息函数到Entry.log()的调用链：

1)logrus.Infof() --> std.Infof()

2)std.Infof()/Logger.Infof() --> NewEntry(logger).Infof(format, args...)

这个std变量是在main()函数调用之前就通过logrus.New()创建，

func New() *Logger {
	return &Logger{
		Out:       os.Stderr,
		Formatter: new(TextFormatter),
		Hooks:     make(LevelHooks),
		Level:     InfoLevel,
	}
}

即std实际是一个Logger()类型的引用，std.Out设置为os.Stderr。

3)NewEntry(logger).Infof(format, args...) --> Entry.log()

这里NewEntry(logger)的参数logger就是前面的std变量，并用它创建一个Entry对象，并初始化Entry.logger

func NewEntry(logger *Logger) *Entry {
	return &Entry{
		Logger: logger,
		// Default is three fields, give a little extra room
		Data: make(Fields, 5),
	}
}

这里的入参logger就是前面的std，而 NewEntry(logger).Infof(format, args...)的最终的实现为：

func (entry *Entry) Info(args ...interface{}) {
	if entry.Logger.Level >= InfoLevel {
		entry.log(InfoLevel, fmt.Sprint(args...))
	}
}

即最终就调用了我们最初讲的entry.log()函数。

这样一路下来，在Entry.log()函数中的etnry.Logger.Out，实际就是std.Out。在调用logrus.New()函数创建std时就将它初始化成了os.Stderr。

那这个os.Stderr就是标准输出，它由golang提供的标准包创建而来。

2.2 os.Stderr的来龙去脉

os.Stderr是golang包中定义的一个全局值，具体定义在/usr/local/go/pkg/os/file.go文件中：

Stderr = NewFile(uintptr(syscall.Stderr), "/dev/stderr")

上面的函数func NewFile(fd uintptr, name string) *File{} 根据入参文件描述符fd和文件路径来创建并返回一个*File类型的值，用于golang的文件读写库函数。

这里NewFile(fd unitptr, name string)两个入参分别是syscall.Stderr和"/dev/stderr"。

第一个参数是syscall.Stderr定义在/usr/local/go/pkg/syscall/syscall_unix.go中，值为Stderr=2，也就是类unix系统中打标准出错设备描述符；第二个参数文件名字为"/dev/stderr"，即标准出错设备。即在golang底层和c语言一样，文件访问也会有文件描述符和文件名。

最终在golang中我们司空见惯的os.Stderr是*File类型的变量，代表着标准出错设备。在golang中进行文件访问时，通常都是通过File结构来进行。

三将信息输出到os.Stderr

有了上面的了解，我们再来看看docker中logrus是如何将打印信息写到os.Stderr的，这里就以io.Copy(entry.Logger.out, reader)为突破口进行分析。

函数io.Copy()的定义如下：

func Copy(dst Writer, src Reader) (written int64, err error) {
	// If the reader has a WriteTo method, use it to do the copy.
	// Avoids an allocation and a copy.
	if wt, ok := src.(WriterTo); ok {
		return wt.WriteTo(dst)
	}
	// Similarly, if the writer has a ReadFrom method, use it to do the copy.
	if rt, ok := dst.(ReaderFrom); ok {
		return rt.ReadFrom(src)
	}
	buf := make([]byte, 32*1024)
	for {
		nr, er := src.Read(buf)
		if nr > 0 {
			nw, ew := dst.Write(buf[0:nr])
			if nw > 0 {
				written += int64(nw)
			}
			if ew != nil {
				err = ew
				break
			}
			if nr != nw {
				err = ErrShortWrite
				break
			}
		}
		if er == EOF {
			break
		}
		if er != nil {
			err = er
			break
		}
	}
	return written, err
}

前面已经提过，io.Copy(dst Writer, src Reader)是将实现了Reader:read()接口方法的src数据写到实现了Writer:write()接口方法的dst变量中。在前面已经分析了，在docker中这里的dst就是os.Stderr；而Reader就是 bytes.Buffer类型的变量。

在这个函数的第一步先判断参数src是否实现了WriterTo方法：

	if wt, ok := src.(WriterTo); ok {	//这里的Reader是bytes.Buffer结构变量，它实现了WriterTo方法
		return wt.WriteTo(dst)
	}

如果src实现了WriterTo方法，就直接通过src.WriterTo(dst)来完成信息从src到dst的写入。这里src作为bytes.Buffer类型，其WriterTo()具体实现如下：

//bytes.Buffer结构实现来WriteTo方法
// WriteTo writes data to w until the buffer is drained or an error occurs.
// The return value n is the number of bytes written; it always fits into an
// int, but it is int64 to match the io.WriterTo interface. Any error
// encountered during the write is also returned.
func (b *Buffer) WriteTo(w io.Writer) (n int64, err error) {
	b.lastRead = opInvalid
	if b.off < len(b.buf) {
		nBytes := b.Len()
		m, e := w.Write(b.buf[b.off:])
		if m > nBytes {
			panic("bytes.Buffer.WriteTo: invalid Write count")
		}
		b.off += m
		n = int64(m)
		if e != nil {
			return n, e
		}
		// all bytes should have been written, by definition of
		// Write method in io.Writer
		if m != nBytes {
			return n, io.ErrShortWrite
		}
	}
	// Buffer is now empty; reset.
	b.Truncate(0)
	return
}

这个函数除去检查部分的代码，信息写入的实现核心就在：

m, e := w.Write(b.buf[b.off:])

实际上bytes.Buffer.WriterTo()实现src到dst写入的功能最终是交由dst.Write(b.buf[b.off:])来实现的，在这里也就是os.Stderr.Write(b.buf[b.off:])，而前面已经讲过os.Stderr是*File类型的变量，因而最终调用的是：

//w.Write 实际调用的是 os.Stderr.Write(),也就是File.Write(b []byte)
//######usr/local/go/pkg/os/file.go
// Write writes len(b) bytes to the File.
// It returns the number of bytes written and an error, if any.
// Write returns a non-nil error when n != len(b).
func (f *File) Write(b []byte) (n int, err error) {
	if f == nil {
		return 0, ErrInvalid
	}
	n, e := f.write(b)
	if n < 0 {
		n = 0
	}
	if n != len(b) {
		err = io.ErrShortWrite
	}

	epipecheck(f, e)

	if e != nil {
		err = &PathError{"write", f.name, e}
	}
	return n, err
}

进一步观察它的核心实现File.Write(b)-->File.write(b)：

//######usr/local/go/pkg/os/file_unix.go
// write writes len(b) bytes to the File.
// It returns the number of bytes written and an error, if any.
func (f *File) write(b []byte) (n int, err error) {
	for {
		bcap := b
		if needsMaxRW && len(bcap) > maxRW {
			bcap = bcap[:maxRW]
		}
		m, err := syscall.Write(f.fd, bcap)
		n += m

		// If the syscall wrote some data but not all (short write)
		// or it returned EINTR, then assume it stopped early for
		// reasons that are uninteresting to the caller, and try again.
		if 0 < m && m < len(bcap) || err == syscall.EINTR {
			b = b[m:]
			continue
		}

		if needsMaxRW && len(bcap) != len(b) && err == nil {
			b = b[m:]
			continue
		}

		return n, err
	}
}

可以看到这个已经是golang底层包的实现函数了，它直接调用syscall包中syscall.Write()函数来实现。它通过一个for{}循环向f.fd写len(bcap)长度的信息bcap。直到完全写完len(bcap)大小的信息或者中途发生出错才退出。这里的f.fd也就是前面讲到的unxi系统中标准出错设备的文件描述符2；bcap是我们想要打印的消息，类型为[]bytes。

看来我们越来越接近真相了，我们再来瞧瞧golang中如何使用系统调用函数syscall.Write()文件：

//######usr/local/go/pkg/syscall/syscall_unix.go
func Write(fd int, p []byte) (n int, err error) {
	if raceenabled {
		raceReleaseMerge(unsafe.Pointer(&ioSync))
	}
	n, err = write(fd, p)
	if raceenabled && n > 0 {
		raceReadRange(unsafe.Pointer(&p[0]), n)
	}
	return
}

syscall.Write()调用来write()函数来实现写文件fd,这个write()函数跟架构相关：

// THIS FILE IS GENERATED BY THE COMMAND AT THE TOP; DO NOT EDIT
//######usr/local/go/pkg/syscall/zsyscal_linux_amd64.go
func write(fd int, p []byte) (n int, err error) {
	var _p0 unsafe.Pointer
	if len(p) > 0 {
		_p0 = unsafe.Pointer(&p[0])
	} else {
		_p0 = unsafe.Pointer(&_zero)
	}
	r0, _, e1 := Syscall(SYS_WRITE, uintptr(fd), uintptr(_p0), uintptr(len(p)))
	n = int(r0)
	if e1 != 0 {
		err = e1
	}
	return
}

噢，看到这里，c语言系的小伙伴终于会心的一笑^_^：最终不就是通过Syscall+系统调用号+参数来实现最终的write系统调用么。来对比一下golang中的Write系统调用和c语言中的Write系统调用的底层库实现：

glibc库：INLINE_SYSCALL_CALL (write, fd, buf, nbytes);

golang：Syscall(SYS_WRITE, uintptr(fd), uintptr(_p0), uintptr(len(p)))

到此终于了解到了整个过程。

总结
下面我们再来总结一下docker中logrus进行终端信息打印的原理。

1 logrus提供了类似fmt.Print()类似的打印功能，如logrus.Debugf()，logrus.Infof()....等等，它将打印信息输出到标准出错设备/dev/stderr。

2 logrus将打印信息msg封装成entry类型，一是用于信息格式化；二是用于日志记录；三是可以创建bytes.Buffer结构用于golang中的文件读写。

3 logrus的信息打印功能，最终使用底层的系统调用包，通过SYS_WRITE系统调用号来实现。