go工程Log4go日志实践

前言

有这样一段话来描述日志对于运维的重要性：“一个成功的软件，全力开发的时间可能占其整个生命周期的1/4还不到，软件发布后要运维（Operation），运维的视角和开发的视角是很不一样的，但是有一点，运维的数据能反哺开发，同时，开发的时候也得考虑可运维性，其中非常重要的一点是日志，没有日志，运维就瞎了大半”。日志的重要性不仅限于此，好的日志能够帮助我们更快更好的定位问题。
最近项目中使用go语言开发的模块增多，开发使用log4go日志框架，但在做测试时碰到两个问题：一是日志分割按照文件大小分割，导致定位问题繁琐；另外一个问题是生成的日志受限，导致日志分析系统不能正常获取相应的日志信息。对于这两个问题笔者进行了相应的调研，下面将解决方法介绍给大家。

1.日志分割

服务端每天产生大量的日志，如何做好日志的分割，是查找日志定位问题的关键，当前对日志的分割采用的是按照文件大小的形式分割的，为了更方便的查找日志，最好的办法便是按日期分割，log4go配置文件中给出了相关的配置项。针对日志文件的主要配置项如下：

<logging>
  <filter enabled="true">
    <tag>file</tag>
    <type>file</type>
    <level>FINEST</level>
    <property name="filename">test.log</property>
    <property name="format">[%D %T] [%L] (%S) %M</property>
    <property name="rotate">true</property> <!-- true enables log rotation, otherwise append -->
    <property name="maxsize">0M</property> <!-- \d+[KMG]? Suffixes are in terms of 2**10 -->
    <property name="maxlines">0K</property> <!-- \d+[KMG]? Suffixes are in terms of thousands -->
    <property name="daily">false</property> <!-- Automatically rotates when a log message is written after midnight -->
  </filter>
</logging>

通过配置项可以看出针对日志分割的几种形式，将最后一行按天分割的配置打开，我们将配置文件做如下修改：

<logging>
  <filter enabled="true">
    <tag>file</tag>
    <type>file</type>
    <level>FINEST</level>
    <property name="filename">test.log</property>
    <property name="format">[%D %T] [%L] (%S) %M</property>
    <property name="rotate">true</property> <!-- true enables log rotation, otherwise append -->   
    <property name="daily">true</property> <!-- Automatically rotates when a log message is written after midnight -->
  </filter>
</logging>

这样生成的日志便是按照天分割，分割后日志形式如下：

test.log  test.log.001  test.log.002

虽然日志是按照我们的要求分割了，但切割后日志文件的名称并不友好，对查找日志还是有些不便，如果我们将切割后的日志文件名称中添加对应日期，会更加方便。分割后的文件名称无法从配置项中体现，为此，分析了log4go的源码，得出下面的信息。

打开开发使用的logo4go源码包，找到日志文件操作的filelog.go文件，在intRotate()函数中有这样一段处理日志持久化的代码：

        // If we are keeping log files, move it to the next available number
    if w.rotate {
        _, err := os.Lstat(w.filename)
        if err == nil { // file exists
            // Find the next available number
            num := 1
            fname := ""
            for ; err == nil && num <= 999999999; num++ {
                fname = w.filename + fmt.Sprintf(".%03d", num)
                _, err = os.Lstat(fname)
            }
            // return error if the last file checked still existed
            if err == nil {
                return fmt.Errorf("Rotate: Cannot find free log number to rename %s\n", w.filename)
            }

            // Rename the file to its newfound home
            err = os.Rename(w.filename, fname)
            if err != nil {
                return fmt.Errorf("Rotate: %s\n", err)
            }
        }
    }

从代码逻辑中很容易看出，当日志文件持久化保存时生成的新的名称只是在原文件名称后面添加了对应的num，为了满足我们的需求，处理很简单，我们可以在文件名称后添加对应的时间信息。重新去拉一份新的logo4go源码进行修改，你会发现源码已经进行了更新，且已经给出了相应的修改方案，新的版本给出如下逻辑：

    // If we are keeping log files, move it to the next available number
    if w.rotate {
        _, err := os.Lstat(w.filename)
        if err == nil { // file exists
            // Find the next available number
            num := 1
            fname := ""
            if w.daily && time.Now().Day() != w.daily_opendate {
                yesterday := time.Now().AddDate(0, 0, -1).Format("2006-01-02")
                for ; err == nil && num <= 999; num++ {
                    fname = w.filename + fmt.Sprintf(".%s.%03d", yesterday, num)
                    _, err = os.Lstat(fname)
                }
            } else {
                for ; err == nil && num <= 999; num++ {
                    fname = w.filename + fmt.Sprintf(".%s.%03d", time.Now().Format("2006-01-02"), num)
                    _, err = os.Lstat(fname)
                }
            }
            // return error if the last file checked still existed
            if err == nil {
                return fmt.Errorf("Rotate: Cannot find free log number to rename %s\n", w.filename)
            }
            w.file.Close()
            // Rename the file to its newfound home
            err = os.Rename(w.filename, fname)
            if err != nil {
                return fmt.Errorf("Rotate: %s\n", err)
            }
        }
    }

新的版本已经引入了日志文件名称的优化，当然我们也可以根据自己的要求去命名日志文件名称。修改后文件名称显示如下：

test.log  test.log.2015-12-01.001  test.log.2015-12-01.002 test.log.2015-12-02.001

2. 日志权限问题

log4go生成的日志默认权限为660，由于我们日志分析系统使用的账户属于不同的组，所以没有权限去读取日志，造成无法收集日志信息并进行分析。同样，权限问题无法在配置文件中进行配置，只能去找源头。
由于是对日志文件的处理，同样打开源码中针对日志文件处理filelog.go文件，打开或者创建一个新的log文件时，源码中在intRotate()方法中是这样处理的：

// Open the log file
    fd, err := os.OpenFile(w.filename, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0660)
    if err != nil {
        return err
    }
    w.file = fd

很明显，打开文件时使用了OpenFile这个方法，方法具体如下：

func OpenFile(name string, flag int, perm FileMode) (file *File, err error)

该方法是通过某种模式打开文件，如果不存在就创建文件，如果存在就追加写，其中三个参数分别为文件路径、打开模式、文件权限，第三个参数便是我们需要设置的。默认的日志文件权限为0660，为了满足我们的需求，将其修改为0664，修改后结果如下：

// Open the log file
    fd, err := os.OpenFile(w.filename, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0664)
    if err != nil {
        return err
    }
    w.file = fd

至此两个问题得到了很好的解决！

本文来自网易实践者社区，经作者刘成授权发布。