如何在Go中以极低的成本为禁用的日志语句执行跟踪日志记录 [英] How to do trace logging in Go with very low cost for disabled log statements

问题描述

将低级调试/跟踪日志记录语句留在关键路径中很有用，以便可以通过运行时配置启用它们.这样的想法是，您永远不会在生产环境中打开此类日志记录(这会削弱性能)，但是您可以 在生产环境中将其打开(例如，生产系统脱机进行调试或完全类似于生产系统的测试系统.

这种类型的日志记录有一个特殊要求:在关键路径上命中 disabled 日志语句的成本必须非常低:理想情况下是一个布尔测试. /p>

在C/C ++中，我将使用LOG宏执行此操作，该宏在检查了标志之前不会评估其任何参数.只有启用后，我们才会调用一些辅助函数来格式化&传递日志消息.

那么如何在Go中做到这一点?

将io.Discard与log.Logger结合使用不是一个入门工具:每次禁用后，它都会完全格式化日志消息，然后丢弃它.

我的第一个念头是

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(...) } }

这很接近.如果我说:

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中的所有参数，并且该语言中没有定义的预处理器宏，因此您只能做几件事.

为避免在记录参数中调用昂贵的函数，请使用fmt.Stringer和fmt.GoStringer接口来延迟格式化，直到执行该函数为止.这样，您仍然可以将普通类型传递给Printf函数.您也可以使用自定义记录器来扩展此模式，该记录器还可以检查各种接口.这就是您在Stringify示例中所使用的，并且您只能通过代码审查和单元测试来真正实施它.

type LogFormatter interface {
    LogFormat() string
}

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

您还可以在运行时通过记录器界面换出整个记录器，或者在构建时使用构建约束，但仍然需要确保没有将昂贵的调用插入到日志参数中.

某些软件包(例如glog)使用的另一种模式是使Logger本身成为布尔型.这并不能完全消除冗长，但会使其更加简洁.

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进行全面生成.

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 :)

解决方案

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.

这篇关于如何在Go中以极低的成本为禁用的日志语句执行跟踪日志记录的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！