log4go的日志滚动处理——生产环境的适配

日志处理有三类使用环境，开发环境DE，测试环境TE，生产环境PE。

前两类可以看成是一类，重要的是屏幕显示——termlog。生产环境中主要用的是socklog 和 filelog，即网络传输日志和文件日志。

基本框架

网络和文件日志的基本框架非常简单：

1. Open file

2. Write log message

3. Close file

golang log 都支持。

// 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.
// The flag argument defines the logging properties.
func New(out io.Writer, prefix string, flag int) *Logger {
        return &Logger{out: out, prefix: prefix, flag: flag}
}

设置不同的io.Writer而已。

type FileWriter struct {
        filename string
        fileflush  int

        file   *os.File
        bufWriter *bufio.Writer
        writer io.Writer
}

func (fw *FileWriter) openFile(flag int) (*os.File, error) {
        fd, err := os.OpenFile(fw.filename, flag, DefaultFilePerm)
        if err != nil {
                return nil, err
        }

        fw.file = fd
        fw.writer = fw.file

        if fw.fileflush > 0 {
                fw.bufWriter = bufio.NewWriterSize(fw.file, fw.fileflush)
                fw.writer = fw.bufWriter
        }
        return fd, nil
}

当然，带缓冲写文件的 bufio，一次写入4k或者8k字节，效率更高。在另一篇文章中已经讨论过了。详见：

log4go的一些改进设想

原来的日志滚动处理

接下来要考虑是日志文件内容日积月累，越来越大怎么办？

在开发和测试环境中，这不是问题。因此常常被忽略，结果进入生产环境后磁盘满溢，系统瘫痪。

记得还是上世纪94年的时候，半夜坐火车到客户那里，在 Novell 服务器上的执行 purge 命令，运行了半个多小时……

所以，日志的滚动处理非常重要。假设滚动日志文件数为1。

1. 日志文件超过一定的大小，触发滚动处理。

2. 将原来存在的文件log.1删除

3. 将当前文件重命名为log.1

4. 等写入新的日志时，再判断文件状态，建立并打开新的日志文件。

于是，日志文件的大小被自动控制在一定范围内。使服务器的磁盘自动保持清洁高效的状态。

log4go v4 的触发滚动处理如下：

func (w *FileLogWriter) LogWrite(rec *LogRecord) {
        now := time.Now()

        if (w.maxlines > 0 && w.maxlines_curlines >= w.maxlines) ||
                (w.maxsize > 0 && w.maxsize_cursize >= w.maxsize) ||
                (w.daily && now.Day() != w.daily_opendate.Day()) {
                // open the file for the first time
                if err := w.intRotate(); err != nil {
                        fmt.Fprintf(os.Stderr, "FileLogWriter(%q): %s\n", w.filename, err)
                        return
                }
        }
}

这意味着：

1. 精确控制日志文件的大小

2. 每次写入日志信息都要做一系列复杂判断

3. 随时可能进行滚动日志处理

4. 当rotate = 0 时，不进行日志滚动处理。这可能是个坑。开发和测试的时候，日志文件的滚动处理可能被忽略。

其实，在生产环境中，什么时候进行滚动处理，才是真正重要的。通常都会选择每天凌晨系统较为空闲的时候。

如果是一个24小时满载的系统，或者对系统稳定性要求特别高，或者对日志的可靠性要求特别高，建议用socklog。

将日志信息发送给专门的日志服务程序进行处理。参照log4go的示例程序，SimpleNetLogServer.go

按照生产环境的要求重写

• 始终进行日志滚动处理。当日志滚动数为0时，超过缺省的文件大小，关闭并删除当前的日志文件。

• 按照生产环境的要求设置缺省文件名，目录，大小，滚动处理的时间和间隔。

• 精确控制滚动处理的时间。详见日志：http://www.cnblogs.com/ccpaging/p/7203431.html

• 支持任意的时间间隔检查日志文件大小。可以每次都转存日志。

• 平时写入日志时不再判断文件大小。

• 简化处理流程。写信息时判断并建立打开当前日志文件。进行滚动处理时，关闭当前日志文件。

• 继续写新的日志与滚动日志文件处理，可并行。为将来压缩日志文件提供了可能。

保证只启动一个日志滚动处理例程

调用日志处理就一句话：

func (f *FileLogWriter) intRotate() {
        f.Lock()
        defer f.Unlock()

        if n, _ := f.SeekFile(0, os.SEEK_CUR); n <= f.maxsize {
                return
        }
        
        // File existed and File size > maxsize
        
        if len(f.footer) > 0 { // Append footer
                f.WriteString(FormatLogRecord(f.footer, &LogRecord{Created: time.Now()}))
        }

        f.CloseFile() 

        if f.rotate <= 0 {
                os.Remove(f.filename)
                return
        }

        // File existed. File size > maxsize. Rotate
        newLog := f.filename + time.Now().Format(".20060102-150405")
        err := os.Rename(f.filename, newLog)
        if err != nil {
                fmt.Fprintf(os.Stderr, "FileLogWriter(%q): Rename to %s. %v\n", f.filename, newLog, err)
                return
        }
        
        go FileRotate(f.filename, f.rotate, newLog)  // 调用日志滚动处理
}

总觉得哪里不对？如果滚动日志检查的时间间隔短，处理的时间意外地长，就有可能出现同时调用两个例程的情况。

这种情况肯定很少发生。一旦发生，就是个深坑。运维的童鞋要骂娘了……此处省略若干字。

好吧。赶紧做一段程序压压惊。

package main

import (
        "fmt"
        "time"
)

type FileRotate struct {
        rotCount int
        rotFiles chan string
}

var (
        DefaultRotateLen = 5
)

func (r *FileRotate) InitRot() {
        r.rotCount = 0
        r.rotFiles = make(chan string, DefaultRotateLen)
}

func (r *FileRotate) RotFile(filename string, rotate int, newLog string) {
        r.rotFiles <- newLog 
        if r.rotCount > 0 {
                fmt.Println("queued", newLog)
                return
        }

        r.rotCount++
        fmt.Println("start")
        for len(r.rotFiles) > 0 {
                file, _ := <- r.rotFiles
                fmt.Println("handle", file)
                time.Sleep(2 * time.Second)
        }
        fmt.Println("quit")
        r.rotCount--
}

func (r *FileRotate) CloseRot() {
        for i := 10; i > 0; i-- {
                if r.rotCount <= 0 {
                        break
                }
                time.Sleep(1 * time.Second)
        }

        close(r.rotFiles)

        // drain the files not rotated
        for file := range r.rotFiles {
                fmt.Println(file)
        }
}

func main() {
        var r FileRotate;
        r.InitRot()
        for i := 0; i < 5; i++ {
                go r.RotFile("filename", 10, fmt.Sprintf("file%d", i))
                time.Sleep(1 * time.Second)
        }
        time.Sleep(5 * time.Second)
        for i := 5; i < 10; i++ {
                go r.RotFile("filename", 10, fmt.Sprintf("file%d", i))
                time.Sleep(1 * time.Second)
        }
        r.CloseRot()
}

希望这段程序能达到以下目的：

1. 需要时启动例程。

2. 只有一个启动例程。

3. 退出系统时，等待例程结束，最多10秒。

newLog的格式为：

newLog := f.filename + time.Now().Format(".20060102-150405")

即使滚动日志处理出现问题，日志也能保存下来。

那么，最后的问题是，log4go可以进入生产环境吗?不试一试？

https://github.com/ccpaging/log4go