GO Logger 日志实践

分析一下用过的打印日志的log包

  1. Go标准库自带log, 这个log的func比较少, 没有区分level, 但足够简单, 有prefix功能, 可以设置flag来控制时间格式, caller的文件名和行数, 其它的标准包如 net/http database/sql 等也用了此包.
  2. 对自带的log进行包装, 加入level, 颜色. 如ngaut/log, 这个log star数并不多, 还是从最近很火的一个项目pingcap/tidb里看到的, 有点小清新的感觉, 但这个log可能只是为tidb使用的, 缺少自带log的一些方法, 导致没法使用在一些可以定制logger的第三方库如gorm中. 于是我fork了一下https://github.com/hanjm/log, 增加了一些方法, 以便可以给gorm用.
  3. 完全自己实现的log, 结构化输出, 通常是key=value或json, 有名的有logrus, zap等. 第一次看到logrus感觉美极了, 于是大量使用, 直到在关注tidb的时候收到带日志的issues邮件, 里面的日志带了caller, 感觉很有用, 于是去搜logrus的issue看有没有这个功能, 搜到了一个issuehttps://github.com/sirupsen/logrus/issues/63, 讨论了三年这个功能还没加上, 只好放弃美丽的logrus, 找到了替代品zap, zap的设计非常好, 定制性强. log是经常调用的代码, 每次调用不可避免地要进行内存分配, 分配次数和每次分配的内存大小将影响性能. 对log内容的处理也是一个涉及到性能的点, 像log.Printf参数是interface{}, logrus的field是map[stirng]interface{}, 打印interface{}只能靠reflect, Go是静态强类型语言, 用反射的开销比较大, 所以zap使用了手动指定类型的方式, 从zap提供的benchmark上开看, 性能提升还是蛮大的, 虽然相比logrus使用起来更麻烦, 但为了性能, 还是值得的.

总结

  1. 为了方便进行日志分析, 统一用json行日志, 这样用elk时可以免去定制正则表达式存储到elasticSearch的field中.
  2. net/http database/sql 及一些第三方包可能直接使用了标注库的log, 有个trick可以改变所有使用标准包log的行为, 通过log.SetOutput(w io.Writer)来改变位置, w是一个实现了Write(p []byte) (n int, err error)方法的io.Writer即可.
  3. runtime.Caller可以得到调用者的pc, 文件名, 文件行数, runtime.FuncForPC(pc).Name()可以得到pc所在的函数名, 对于debug非常有帮助. 但有一定性能开销, 所以方案是: 对于http server的access log, 没有必要使用带caller的日志, 而对于http api具体实现的函数内的log, 有必要记录caller, 而且光有文件名和行数还不够, 毕竟改了代码行数就变了, 而函数名一般不会变, 带上函数名会更直观.
  4. GitHub搜了一圈, 好多公司都会定制自己的log, 如tidb的ngaut/log, 七牛的qiniu/log, 饿了么的eleme/log, mailgun的mailgun/log, 是的, 我也造一个小轮子zaplog.zaplog是包装了zap, 带caller func name, 兼容logrus stdlog 的日志输出工具.
package zaplog
import (
"bytes"
"fmt"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
"log"
"runtime"
"strings"
)
// CallerEncoder will add caller to log. format is "filename:lineNum:funcName", e.g:"zaplog/zaplog_test.go:15:zaplog.TestNewLogger"
func CallerEncoder(caller zapcore.EntryCaller, enc zapcore.PrimitiveArrayEncoder) {
enc.AppendString(strings.Join([]string{caller.TrimmedPath(), runtime.FuncForPC(caller.PC).Name()}, ":"))
}
func newLoggerConfig(debugLevel bool) (loggerConfig zap.Config) {
loggerConfig = zap.NewProductionConfig()
loggerConfig.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
loggerConfig.EncoderConfig.EncodeCaller = CallerEncoder
if debugLevel {
loggerConfig.Level = zap.NewAtomicLevelAt(zap.DebugLevel)
}
return
}
// NewCustomLoggers is a shortcut to get normal logger, noCallerLogger.
func NewCustomLoggers(debugLevel bool) (logger, noCallerLogger *zap.Logger) {
loggerConfig := newLoggerConfig(debugLevel)
logger, err := loggerConfig.Build()
if err != nil {
panic(err)
}
loggerConfig.DisableCaller = true
noCallerLogger, err = loggerConfig.Build()
if err != nil {
panic(err)
}
return
}
// NewLogger return a normal logger
func NewLogger(debugLevel bool) (logger *zap.Logger) {
loggerConfig := newLoggerConfig(debugLevel)
logger, err := loggerConfig.Build()
if err != nil {
panic(err)
}
return
}
// NewNoCallerLogger return a no caller key value, will be faster
func NewNoCallerLogger(debugLevel bool) (noCallerLogger *zap.Logger) {
loggerConfig := newLoggerConfig(debugLevel)
loggerConfig.DisableCaller = true
noCallerLogger, err := loggerConfig.Build()
if err != nil {
panic(err)
}
return
}
// CompatibleLogger is a logger which compatible to logrus/std log/prometheus.
// it implements Print() Println() Printf() Dbug() Debugln() Debugf() Info() Infoln() Infof() Warn() Warnln() Warnf()
// Error() Errorln() Errorf() Fatal() Fataln() Fatalf() Panic() Panicln() Panicf() With() WithField() WithFields()
type CompatibleLogger struct {
_log *zap.Logger
}
// NewCompatibleLogger return CompatibleLogger with caller field
func NewCompatibleLogger(debugLevel bool) *CompatibleLogger {
return &CompatibleLogger{NewLogger(debugLevel).WithOptions(zap.AddCallerSkip(1))}
}
// Print logs a message at level Info on the compatibleLogger.
func (l CompatibleLogger) Print(args ...interface{}) {
l._log.Info(fmt.Sprint(args...))
}
// Println logs a message at level Info on the compatibleLogger.
func (l CompatibleLogger) Println(args ...interface{}) {
l._log.Info(fmt.Sprint(args...))
}
// Printf logs a message at level Info on the compatibleLogger.
func (l CompatibleLogger) Printf(format string, args ...interface{}) {
l._log.Info(fmt.Sprintf(format, args...))
}
// Debug logs a message at level Debug on the compatibleLogger.
func (l CompatibleLogger) Debug(args ...interface{}) {
l._log.Debug(fmt.Sprint(args...))
}
// Debugln logs a message at level Debug on the compatibleLogger.
func (l CompatibleLogger) Debugln(args ...interface{}) {
l._log.Debug(fmt.Sprint(args...))
}
// Debugf logs a message at level Debug on the compatibleLogger.
func (l CompatibleLogger) Debugf(format string, args ...interface{}) {
l._log.Debug(fmt.Sprintf(format, args...))
}
// Info logs a message at level Info on the compatibleLogger.
func (l CompatibleLogger) Info(args ...interface{}) {
l._log.Info(fmt.Sprint(args...))
}
// Infoln logs a message at level Info on the compatibleLogger.
func (l CompatibleLogger) Infoln(args ...interface{}) {
l._log.Info(fmt.Sprint(args...))
}
// Infof logs a message at level Info on the compatibleLogger.
func (l CompatibleLogger) Infof(format string, args ...interface{}) {
l._log.Info(fmt.Sprintf(format, args...))
}
// Warn logs a message at level Warn on the compatibleLogger.
func (l CompatibleLogger) Warn(args ...interface{}) {
l._log.Warn(fmt.Sprint(args...))
}
// Warnln logs a message at level Warn on the compatibleLogger.
func (l CompatibleLogger) Warnln(args ...interface{}) {
l._log.Warn(fmt.Sprint(args...))
}
// Warnf logs a message at level Warn on the compatibleLogger.
func (l CompatibleLogger) Warnf(format string, args ...interface{}) {
l._log.Warn(fmt.Sprintf(format, args...))
}
// Error logs a message at level Error on the compatibleLogger.
func (l CompatibleLogger) Error(args ...interface{}) {
l._log.Error(fmt.Sprint(args...))
}
// Errorln logs a message at level Error on the compatibleLogger.
func (l CompatibleLogger) Errorln(args ...interface{}) {
l._log.Error(fmt.Sprint(args...))
}
// Errorf logs a message at level Error on the compatibleLogger.
func (l CompatibleLogger) Errorf(format string, args ...interface{}) {
l._log.Error(fmt.Sprintf(format, args...))
}
// Fatal logs a message at level Fatal on the compatibleLogger.
func (l CompatibleLogger) Fatal(args ...interface{}) {
l._log.Fatal(fmt.Sprint(args...))
}
// Fatalln logs a message at level Fatal on the compatibleLogger.
func (l CompatibleLogger) Fatalln(args ...interface{}) {
l._log.Fatal(fmt.Sprint(args...))
}
// Fatalf logs a message at level Fatal on the compatibleLogger.
func (l CompatibleLogger) Fatalf(format string, args ...interface{}) {
l._log.Fatal(fmt.Sprintf(format, args...))
}
// Panic logs a message at level Painc on the compatibleLogger.
func (l CompatibleLogger) Panic(args ...interface{}) {
l._log.Panic(fmt.Sprint(args...))
}
// Panicln logs a message at level Painc on the compatibleLogger.
func (l CompatibleLogger) Panicln(args ...interface{}) {
l._log.Panic(fmt.Sprint(args...))
}
// Panicf logs a message at level Painc on the compatibleLogger.
func (l CompatibleLogger) Panicf(format string, args ...interface{}) {
l._log.Panic(fmt.Sprintf(format, args...))
}
// With return a logger with an extra field.
func (l *CompatibleLogger) With(key string, value interface{}) *CompatibleLogger {
return &CompatibleLogger{l._log.With(zap.Any(key, value))}
}
// WithField return a logger with an extra field.
func (l *CompatibleLogger) WithField(key string, value interface{}) *CompatibleLogger {
return &CompatibleLogger{l._log.With(zap.Any(key, value))}
}
// WithFields return a logger with extra fields.
func (l *CompatibleLogger) WithFields(fields map[string]interface{}) *CompatibleLogger {
i := 0
var clog *CompatibleLogger
for k, v := range fields {
if i == 0 {
clog = l.WithField(k, v)
} else {
clog = clog.WithField(k, v)
}
i++
}
return clog
}
// FormatStdLog set the output of stand package log to zaplog
func FormatStdLog() {
log.SetFlags(log.Llongfile)
log.SetOutput(&logWriter{NewNoCallerLogger(false)})
}
type logWriter struct {
logger *zap.Logger
}
// Write implement io.Writer, as std log's output
func (w logWriter) Write(p []byte) (n int, err error) {
i := bytes.Index(p, []byte(":")) + 1
j := bytes.Index(p[i:], []byte(":")) + 1 + i
caller := bytes.TrimRight(p[:j], ":")
// find last index of /
i = bytes.LastIndex(caller, []byte("/"))
// find penultimate index of /
i = bytes.LastIndex(caller[:i], []byte("/"))
w.logger.Info("stdLog", zap.ByteString("caller", caller[i+1:]), zap.ByteString("log", bytes.TrimSpace(p[j:])))
return len(p), nil
}
分享到 评论

Linux Cli下酷工具收集(持续)

  1. mycli. ipython之于Python, mycli之于mysql. 当然还有pgcli. Python写的工具. mycli Github地址:https://github.com/dbcli/mycli
  2. youtube-dl. youtube下载器, 能直接下载youtube视频列表. Python写的工具.
  3. oh-my-zsh的z命令. 手动输入一个很长的路径名不停地tab很麻烦, 配置了oh-my-zsh的话可以启用z命令(edit: ~/.zshrc line: plugins=(git python z tmux)), z 文件夹名 就可以跳转到常用目录中最符合输入文件夹名的文件夹中, 非常方便, GitHub地址https://github.com/robbyrussell/oh-my-zsh
  4. privoxy. brew pip npm install、docker pull总是慢如蜗牛? privoxy能将shadowsocks的socks代理(127.0.0.1:1080)转换为http/https代理, 有个奇特的地方是把它把文档写在配置文件的注释里, config文件有2271行, 初让人以为配置起来会巨复杂, 实际上基本的功能两行配置即可. listen-address配置为0.0.0.0:8118, 局域网内其他设备也可以走此代理:8118. 官网https://www.privoxy.org/

    listen-address 0.0.0.0:8118
    forward-socks5 / localhost:1080 .

    然后在.zshrc或.bashrc中加入一下命令就可以通过proxy dproxy来切换是否在本终端下使用代理了.

    function proxy(){
    export http_proxy=http://127.0.0.1:8118
    export https_proxy=https://127.0.0.1:8118
    }
    function dproxy(){
    unset http_proxy
    unset https_proxy
    }
  5. kcptun. bandwagon上的shadowsocks越来越慢, 不用kcptun加速没法正常使用, 只能不太厚道地超量发包了. GitHub地址https://github.com/xtaci/kcptun

分享到 评论