如何在Go中进行跟踪日志记录,以实现对禁用日志语句的低成本处理。

huangapple go评论95阅读模式
英文:

How to do trace logging in Go with very low cost for disabled log statements

问题

在关键路径中保留低级调试/跟踪日志记录语句是有用的,这样可以通过运行时配置来启用它们。想法是在生产环境中永远不要打开此类日志记录(这会降低性能),但是可以在生产环境的环境中打开它(例如,为了调试而将生产系统下线或者设置与生产系统完全相同的测试系统)。

这种类型的日志记录有一个特殊要求:在关键路径上禁用的日志记录语句的成本必须非常低:最好只是一个布尔测试。

在C/C++中,我会使用一个LOG宏,在检查标志之前不评估任何参数。只有在启用时,我们才调用一些辅助函数来格式化和传递日志消息。

那么在Go中该如何做呢?

使用io.Discard和log.Logger是不可行的:它会在禁用时每次都完全格式化日志消息,然后将其丢弃。

我的第一个想法是:

type EnabledLogger struct { Enabled bool; delegate *log.Logger;... }
// 将log.Logger接口方法实现为:
func (e EnabledLogger) Print(...) { if e.Enabled { e.delegate.Output(...) } }

这很接近。如果我这样说:

myEnabledLogger.Printf("foo %v: %v", x, y)

如果禁用了,它不会格式化或记录任何内容,但是它会评估参数x和y。对于基本类型或指针来说这没问题,但对于任意函数调用来说就不行了,例如对没有String()方法的值进行字符串化。

我看到两种解决方法:

使用包装类型来延迟调用:

type Stringify { x *Thing }
func (s Stringify) String() { return someStringFn(s.x) }
enabledLogger.Printf("foo %v", Stringify{&aThing})

在整个过程中手动进行启用检查:

if enabledLog.Enabled {
     enabledLog.Printf("foo %v", someStringFn(x))
}

这两种方法都很冗长且容易出错,很容易有人忘记一步并悄悄引入严重的性能退化。

我开始喜欢Go了。请告诉我它能解决这个问题 如何在Go中进行跟踪日志记录,以实现对禁用日志语句的低成本处理。

英文:

It is useful to leave low-level debug/trace logging statements in critical paths so that they can be enabled by runtime configuration. The idea is you never turn such logging on in production (it would cripple performance) but you can turn it on in a production environment (e.g. production system taken offline for debugging or a test system that is set up exactly like the production system.)

This type of logging has a special requirement: the cost of hitting a disabled log statement on a critical path must be very low: ideally a single boolean test.

In C/C++ I would do this with a LOG macro that does not evaluate any of its arguments until it has checked a flag. Only if enabled do we call some helper function to format & deliver the log message.

So how to do this in Go?

Using io.Discard with log.Logger is a non starter: it completely formats the log message every time before throwing it away if disabled.

My first thought is

type EnabledLogger struct { Enabled bool; delegate *log.Logger;... }
// Implement the log.Logger interface methods as:
func (e EnabledLogger) Print(...) { if e.Enabled { e.delegate.Output(...) } }

This is close. If I say:

myEnabledLogger.Printf("foo %v: %v", x, y)

It won't format or log anything if disabled but it will evaluate the arguments x and y. That's OK for basic types or pointers, not OK for arbitrary function calls - e.g. to stringify values that don't have a String() method.

I see two ways around that:

Wrapper types to defer the call:

type Stringify { x *Thing }
func (s Stringify) String() { return someStringFn(s.x) }
enabledLogger.Printf("foo %v", Stringify{&aThing})

Wrap the whole thing in a manual enabled check:

if enabledLog.Enabled {
     enabledLog.Printf("foo %v", someStringFn(x))
}

Both are verbose and error prone, it is too easy for someone to forget a step and quietly introduce a nasty performance regression.

I'm starting to like Go. Please tell me it can solve this problem 如何在Go中进行跟踪日志记录,以实现对禁用日志语句的低成本处理。

答案1

得分: 2

在Go语言中,所有的参数都保证会被求值,而且语言中没有定义预处理器宏,所以你只能做一些有限的事情。

为了避免在日志参数中进行昂贵的函数调用,可以利用fmt.Stringerfmt.GoStringer接口来延迟格式化,直到函数执行时再进行。这样你仍然可以将普通类型传递给Printf函数。你可以通过自定义日志记录器来扩展这个模式,该记录器还会检查各种接口。这就是你在Stringify示例中使用的方式,你只能通过代码审查和单元测试来强制执行它。

type LogFormatter interface {
    LogFormat() string
}

// 在日志记录器内部
if i, ok := i.(LogFormatter); ok {
    fmt.Println(i.LogFormat())
}

你还可以通过日志记录器接口在运行时替换整个日志记录器,或者在构建时使用构建约束完全替换它,但仍需要确保不会在日志参数中插入昂贵的调用。

另一种模式是一些包(如glog)使用的,即将日志记录器本身作为布尔值。这并不能完全消除冗长性,但可以使代码更简洁一些。

type Log bool
func (l Log) Println(args ...interface{}) {
    fmt.Println(args...)
}

var debug Log = false

if debug {
    debug.Println("DEBUGGING")
}

在Go语言中,最接近预处理宏的方法是使用代码生成。这对于运行时可配置的跟踪可能行不通,但至少可以提供一个单独的调试构建,需要时可以直接使用。它可以简单地使用gofmt -r,使用text/template构建一个文件,或者通过解析代码并构建AST来进行完整的代码生成。

英文:

All arguments in Go are guaranteed to be evaluated, and there's no defined preprocessor macros in the language, so there's only a couple things you can do.

To avoid expensive function calls in the logging arguments, make use of the fmt.Stringer and fmt.GoStringer interfaces to delay formatting until the function is executed. That way you can still pass the plain types to Printf functions. You can extend this pattern yourself with a custom logger that checks for various interfaces as well. This is what you're using in your Stringify example, and you can only really enforce it with code review and unit tests.

type LogFormatter interface {
	LogFormat() string
}

// inside the logger
if i, ok := i.(LogFormatter); ok {
	fmt.Println(i.LogFormat())
}

You can also swap out the entire logger out at runtime via a logger interface, or replace it entirely at build time using build constraints, but still requires ensuring no expensive calls are inserted into the logging arguments.

Another pattern used by some packages like glog is to make the Logger itself a bool. This doesn't eliminate the verbosity completely, but it makes it a little more terse.

type Log bool
func (l Log) Println(args ...interface{}) {
	fmt.Println(args...)
}

var debug Log = false

if debug {
    debug.Println("DEBUGGING")
}

The closest you can get to a macro pre-processing in go is to use code generation. This isn't going to work for runtime configurable tracing, but could at least provide a separate debug build that can be dropped into place when needed. It can be as simple as gofmt -r, building a file using text/template, or full generation by parsing the code and building an AST.

答案2

得分: 1

首先,我应该说我个人会选择最简单的解决方案,只使用一个 if 语句。但是如果你真的想要可靠地实现它,你可以使用匿名函数:

type verbose bool

func (v verbose) Run(f func()) {
    if v {
        f()
    }
}

像这样使用它:

v := verbose(false)
v.Run(func() {
    log.Println("No Print")
})

带有昂贵调用的 Playground 示例:http://play.golang.org/p/9pm2HoQQ8A。

英文:

First of all, I should say that I personally would go with the simplest solution and just use an if. But if you really want to do it reliably, you can use anonymous functions:

type verbose bool

func (v verbose) Run(f func()) {
	if v {
		f()
	}
}

Use it like this:

v := verbose(false)
v.Run(func() {
	log.Println("No Print")
})

Playground example with expensive calls: http://play.golang.org/p/9pm2HoQQ8A.

huangapple
  • 本文由 发表于 2015年4月29日 22:28:11
  • 转载请务必保留本文链接:https://go.coder-hub.com/29946675.html
匿名

发表评论

匿名网友

:?: :razz: :sad: :evil: :!: :smile: :oops: :grin: :eek: :shock: :???: :cool: :lol: :mad: :twisted: :roll: :wink: :idea: :arrow: :neutral: :cry: :mrgreen:

确定