Golang 优化之路——自己造一个日志轮子

写在前面

Golang 的log包内容不多,说实话,直接用来做日志开发有些简易。主要是缺少一些功能:

  1. 按日志级别打印和控制日志;
  2. 日志文件自动分割;
  3. 异步打印日志。

按日志级别打印和控制日志

我们实现的日志模块将会支持4个级别:

const (
    LevelError = iota
    LevelWarning
    LevelInformational
    LevelDebug
)

定义一个日志结构体:

type Logger struct {
    level int
    l     *log.Logger
}

func (ll *Logger) Error(format string, v ...interface{}) {
    if LevelError > ll.level {
        return
    }
    msg := fmt.Sprintf("[E] "+format, v...)
    ll.l.Printf(msg)
}

这样就能实现日志级别控制输出,并且打印的时候追加一个标记,比如上面的例子,Error 级别就会追加[E]

这个实现已经可以了,但是还是有优化的空间。比如打印追加标记[E]的时候,用的是字符串加法。字符串加法会申请新的内存,对性能不是很优化。我们需要通过字符数组来优化。

但我不会这么去优化了。这个时候看一下 log 包的 API,可以发现原生包是支持设置前缀的:

func (l *Logger) SetPrefix(prefix string)

再去看一下具体的实现:

func (l *Logger) formatHeader(buf *[]byte, t time.Time, file string, line int) {
    *buf = append(*buf, l.prefix...)

原生包在写日志前缀的时候就用到了[]byte来提升性能。既然人家已经提供了,我们还是不要自己造了。那么问题来了,设置前缀是初始化的时候就要设置,打印的时候自动输出出来。一个log.Logger对象只能有一个前缀,而我们需要4种级别的前缀,这个如何打印?

type Logger struct {
    level int
    err   *log.Logger
    warn  *log.Logger
    info  *log.Logger
    debug *log.Logger
}

我们直接申请4个日志对象就能解决。为了保证所有级别都打印到同一个文件里面,初始化的时候设置成同一个io.Writer即可。

logger := new(LcLogger)

logger.err = log.New(w, "[E] ", flag)
logger.warn = log.New(w, "[W] ", flag)
logger.info = log.New(w, "[I] ", flag)
logger.debug = log.New(w, "[D] ", flag)

设置日志级别:

func (ll *Logger) SetLevel(l int) {
    ll.level = l
}

打印的时候根据日志级别控制输出。(讲一个我遇到的坑。之前有一次打印日志打太多了,磁盘都打满了,就寻思着把日志级别调高减少打印内容。把级别调成 Error 后发现还是没有效果,最后看了看代码发现出问题的日志打印的是 Error 级别。。。Error级别的日志要尽量少打。)

func (ll *Logger) Error(format string, v ...interface{}) {
    if LevelError > ll.level {
        return
    }
    ll.err.Printf(format, v...)
}

日志文件自动分割

日志文件需要自动分割。否则一个文件过大,清理磁盘的时候这个文件因为还是打印日志没办法清理。

日志分割我觉得简单的以大小分割就好。

那么日志分割功能如何接入咱们上面实现的日志模块呢?关键就在io.Writer

type Writer interface {
    Write(p []byte) (n int, err error)
}

Writer这个接口只有一个方法,如此简单。原生包默认打印日志会输出到os.Stderr里面,这是一个os.File类型的变量,它实现了Writer这个接口。

func (f *File) Write(b []byte) (n int, err error)

写日志的时候,log 包会自动调用Write方法。我们可以自己实现一个Writer,在Write的时候计算一下写入此行日志之后当前日志文件大小,如果超过设定的值,执行一次分割。按日子分割日志也是这个时候操作。

推荐用 gopkg.in/natefinch/lumberjack.v2 这个包来做日志分割,功能很强大。

jack := &lumberjack.Logger{
    Filename: lfn,
    MaxSize:  maxsize, // megabytes
}

使用也很简单,jack对象就是一个Writer了,可以直接复制给Logger使用。

日志的异步输出

协程池也整个包:github.com/ivpusic/grpool。协程池就不展开说了,有兴趣的可以看看这个包的实现。

日志的结构体再一次升级:

type Logger struct {
    level int
    err   *log.Logger
    warn  *log.Logger
    info  *log.Logger
    debug *log.Logger
    p     *grpool.Pool
}

初始化:

logger.p = grpool.NewPool(numWorkers, jobQueueLen)

日志输出:

func (ll *Logger) Error(format string, v ...interface{}) {
    if LevelError > ll.level {
        return
    }
    ll.p.JobQueue <- func() {
        ll.err.Printf(format, v...)
    }
}

日志行号

如果你一步一步按上面的做了,打印日志设置了Lshortfile,展示行号的花,你可能会发现这个时候打印出来的行号有问题。打印日志的时候用到了runtime里面的堆栈信息,因为我们封装了一层,所以打印的堆栈深度会发生变化。简单的说就是深了一层。

原生的日志包提供了func (l *Logger) Output(calldepth int, s string) error来控制日志堆栈深度输出,我们再次对代码进行调整。

type Logger struct {
    level int
    err   *log.Logger
    warn  *log.Logger
    info  *log.Logger
    debug *log.Logger
    p     *grpool.Pool
    depth int
}

func (ll *Logger) Error(format string, v ...interface{}) {
    if LevelError > ll.level {
        return
    }
    ll.p.JobQueue <- func() {
        ll.err.Output(ll.depth, fmt.Sprintf(format, v...))
    }
}

我们只封装了一层,所以深度设置成3就可以了。

线程安全

原生包打印日志是线程安全的:

func (l *Logger) Output(calldepth int, s string) error {
    now := time.Now() // get this early.
    var file string
    var line int
    l.mu.Lock() // 看到这里了么?
    defer l.mu.Unlock()
    if l.flag&(Lshortfile|Llongfile) != 0 {
        // release lock while getting caller info - it's expensive.
        l.mu.Unlock()
        var ok bool
        _, file, line, ok = runtime.Caller(calldepth)
        if !ok {
            file = "???"
            line = 0
        }
        l.mu.Lock()
    }
    l.buf = l.buf[:0]
    l.formatHeader(&l.buf, now, file, line)
    l.buf = append(l.buf, s...)
    if len(s) == 0 || s[len(s)-1] != '\n' {
        l.buf = append(l.buf, '\n')
    }
    _, err := l.out.Write(l.buf)
    return err
}

有它的保证,我们也不需要考虑线程安全的问题了。

那么问题来了,fmt包打印日志是线程安全的么?println安全么?fmtprintln打印日志都打印到了哪里?有兴趣的可以留言一下一起讨论。

最后

日志的打印会用到诸如fmt.Sprintf的东西,这个在实现的时候将会用到反射。反射会对性能有影响,但是不用反射的话代码过于恶心。

完整的代码放到了 GitHub 上面,地址

上面介绍的日志只是在针对输出到文件。如果你想输出有邮件、ElasticSearch等其它地方,不要在初始化的时候通过各种复杂配置参数来实现。

我说的是这样:

NewLogger("es", ...)
NewLogger("smtp", ...)

这样做的问题就是,我只能用你提供好的东西,如果想扩展只能修改日志包了。如果这个包是第三方的包,那让别人怎么扩展呢?而且这种实现也不是 Golang 的实现风格。

其实大家看看原生的这些包,很多都是通过接口串联起来的。原生的 log 包,你可以认为他提供的服务主要是流程方面的服务,拼接好要打印的内容,包括行号、时间等等,保证线程安全,然后调用Writer来打印。如果我们要把日志打印到 ES 里面,就实现一个ESWriter。这才是 Golang 风格的代码。


参考文献

  • 【1】《Go 语言实战》
最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 158,233评论 4 360
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 67,013评论 1 291
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 108,030评论 0 241
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 43,827评论 0 204
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 52,221评论 3 286
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 40,542评论 1 216
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 31,814评论 2 312
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 30,513评论 0 198
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 34,225评论 1 241
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 30,497评论 2 244
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 31,998评论 1 258
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 28,342评论 2 253
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 32,986评论 3 235
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 26,055评论 0 8
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 26,812评论 0 194
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 35,560评论 2 271
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 35,461评论 2 266

推荐阅读更多精彩内容