Reimplement log/experimental_levels #470
Conversation
| // Info, Warn or Error helper methods are squelched and non-leveled log | ||
| // events are passed to next unmodified. | ||
| func NewFilter(next log.Logger, options ...Option) log.Logger { | ||
| l := &logger{ |
There was a problem hiding this comment.
Any technical reason for moving the pointer here instead of passing it as option(&l)?
After some discussions with @goinggo I've taken to passing with & because it implies the semantic meaning of "I'm sharing this to be modified"
Just interested in the discussion on readability and performance with the declarations here :)
There was a problem hiding this comment.
I don't think there is any technical reason. The reason I moved it is because type logger has a pointer receiver on its Log method so it must be a pointer in the returned log.Logger interface value to satisfy the interface. I prefer to create it in the same form that it will live its life, as a *logger.
| } | ||
| }) | ||
| } | ||
| }) |
| logger := tc.format(&buf) | ||
| level.Info(logger).Log("foo", "bar") | ||
| if want, have := tc.output, strings.TrimSpace(buf.String()); want != have { | ||
| t.Errorf("\nwant: '%s'\nhave '%s'", want, have) |
There was a problem hiding this comment.
Out of curiosity, what does %q yield on Windows?
There was a problem hiding this comment.
%q works the same on all platforms as it is geared towards escaping strings like you would see in Go source code. It is often unsatisfactory when printing Windows file paths because the \s get doubled up, but that's not my motivation here. In this case the motivation is that I added a test that outputs JSON and didn't want to see lots of \" in the output.
IMO, %q should be used when the intent is for escaped strings. If you just want to demarcate the beginning and ending of a string (to spot extra white space or spot empty strings) then explicit markers are preferred.
Of course now I am thinking that perhaps ` would be better than ' for Go because of its use within the language for unescaped string literals.
log/experimental_level/level.go
Outdated
| // AllowDebugAndAbove allows all of the four default log levels. | ||
| func AllowDebugAndAbove() Option { | ||
| return allowed(levelDebug | levelInfo | levelWarn | levelError) | ||
| } |
There was a problem hiding this comment.
Looking at this through the fresh eyes of someone reviewing the Proposal doc, I'm raising my eyebrow a little bit at the AllowFooAndAbove nomenclature, specifically the AndAbove bit, which seems necessarily implicit. Therefore the bitfield implementation here, which allows arbitrary selection of levels, may be needless. What do you think about this patch?
There was a problem hiding this comment.
@peterbourgon, that's the inverse of my earlier commit in #453 ("Use a mask to filter log records by level"). I started with the inequality that you propose here, but found that the bitmask implementation beat it in my benchmarks. Unfortunately, I didn't include the improvement in the commit message, but I recall it being on the order of 3%. It's worth testing again.
There was a problem hiding this comment.
Hmm. My philosophy tends to be that any code change that deviates from a naive, intuitive implementation needs a degree of justification proportionate to that deviation. There is a lot of subjectivity built in to that criteria, unfortunately. To my subjective eyes, bitmasking levels in this way is enough of a headscratcher that I'd want to see a much clearer win than a 3% performance improvement. With that objection raised, I defer to Chris' final call.
There was a problem hiding this comment.
I agree that thinking of the levels as being ordered significantly and comparing via inequality is more intuitive. My goal in #453 was to "build a race car," so for each operation I was trying to find the fastest way to achieve the same functional outcome.
There was a problem hiding this comment.
I would love to see the exported function names get less verbose. In particular I think the current AndAbove terminology is not always intuitive because I often think of level error as more critical than level info and therefore above it in some way. I am not sure that everyone has the same intuition about which levels are the "high" levels and which are the "low" levels. I've seen both philosophies implemented in various logging libraries.
I do think it is generally accepted that level info is a superset of level warn which is a superset of level error from an output perspective. I think that intuition is what our exported API should lean on.
I am not too concerned about the implementation details. I am fine either way. If we can measure a consistent performance difference I would be inclined to go with the faster implementation along with an appropriate level of justification in internal comments.
There was a problem hiding this comment.
I'm relieved to see another acknowledgment that the order of these common levels is inconsistent in different libraries. I recall disagreeing with log15's ordering, which puts "critical" at the bottom/lowest and "debug" at the top/highest. "Severity" is an ordering that people will understand, but using function names like "InfoAndMoreSevere" didn't ring well to my ear.
There was a problem hiding this comment.
Great, so shall we leave the bitmasking as-is, and rename the options?
There was a problem hiding this comment.
Yes, let's focus on the exported names and API for now. I think the option names can be improved.
|
While working on the proposal, it struck me that a great feature for NewFilter would be an option to promote unleveled log records to leveled, at a chosen level, on an opt-in basis. What do you think? |
That might be useful to some people, but I think it should be implemented as a new Outline of one approachMy first idea was to export the level values and provide the following function. func NewInjector(logger log.Logger, level *levelValue) log.LoggerWhich actually works even though func NewInjector(next log.Logger, level Value) log.Logger
type Value interface {
String() string
levelVal()
}
func Key() interface{} { return key }
func ErrorValue() Value { return errorValue }
func WarnValue() Value { return warnValue }
func InfoValue() Value { return infoValue }
func DebugValue() Value { return debugValue }
var (
key interface{} = "level"
errorValue = &levelValue{level: levelError, name: "error"}
warnValue = &levelValue{level: levelWarn, name: "warn"}
infoValue = &levelValue{level: levelInfo, name: "info"}
debugValue = &levelValue{level: levelDebug, name: "debug"}
)
type levelValue struct {
name string
level
}
func (v *levelValue) String() string { return v.name }
func (v *levelValue) levelVal() {}Providing the An application would use var logger log.Logger
logger = log.NewLogfmtLogger(os.Stdout)
logger = level.NewInjector(logger, level.InfoValue())I have this coded up with a unit test but no docs yet. Let me know if this looks worth adding and I'll finish it up and add it to this PR. |
|
Brilliant. Looks great to me. The |
|
I'm leery of the utility in exposing the level values like this, even behind these functions. Though it sounds like you did consider an alternative like this, I'll describe it just to solicit your reaction. What if instead of exporting these six new symbols (a type and five functions), you instead exported four functions like this:
Each fixes We use the word "default" all the time in programming, but here it feels especially apt: for lack of a specified alternative, we use this value. |
|
Why are you leery of exposing level values? I think it's great: it means users may implement their own identical decorators, or even fall back to a more explicit behavior. If we can explain that level.Debug(logger).Log("msg", "hello")is just sugar for logger.Log(level.Key(), level.DebugValue(), "msg", "hello")then the package gets a lot more understandable, IMO. |
|
Doing so allows use of the level value in a key position, which one could emulate well enough with a bare string key, but it seems like the filtering It's no worse than it was with strings as the keys and values, but with the private type we have the opportunity to constrain its use. It sounds like you see opening it back up more as an opportunity than a liability. I don't have any real examples of potential misuse here. That's why I said "leery," as opposed to "vehemently opposed." The threat I described over in #453 is more likely to arise. |
|
I am not sympathetic to the concerns about misuse. This package provides convenient helpers that ensure the usage is correct. Code that chooses to use the individual values must also assume the responsibility of doing so correctly. There is little we can do about code using string values that match the results of the I am also not sure how I feel about the fact that this PR will require packages to use its types in order to be compatible with its filter. That is not the case with the existing string based approach. Having said that, exporting the |
That is where one of the allocations is saved. Preallocating those as interface values avoids an allocation per Granted it does make the return type of |
You could convert it back and return a string from |
Perfect. Perhaps a comment to this effect?
No need. |
|
Ready for review. /cc @peterbourgon @seh |
log/experimental_level/level.go
Outdated
| type Option func(*logger) | ||
| // NewInjector wraps next and returns a logger that adds a Key/level pair to | ||
| // the beginning of log events that don't already contain a level. | ||
| func NewInjector(next log.Logger, level Value) log.Logger { |
There was a problem hiding this comment.
"In effect, this gives a default level to logs without a level key."
|
With that small addition to the comment on NewInjector, |
Reimplement log/experimental_levels
The main focus here is to get away from identifying level keyvals with string matching and use type matching with a bit set for level filtering in the manner demonstrated by @seh in #453.
I am very happy that all of the configuration options could be preserved. I have taken the liberty to simplify the
OptionsAPI a bit to make it friendlier. TheAllowedoption was removed in favor of converting all of its helper functions (e.g.AllowInfoAndAbove) into functional Options that can be used directly. I also changedlevel.Newtolevel.NewFilterbecause it better expresses its purpose.The documentation is updated and corrected.
Before updating the implementation I rewrote the benchmarks to be more comprehensive with the use of the new (Go 1.7) sub-benchmark feature. The before and after results of the benchmarks follow.
Updated benchmarks after 6a12b31.