Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Re-introduce terse configuration #274

Merged
merged 11 commits into from
Feb 10, 2017
227 changes: 227 additions & 0 deletions config.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,227 @@
// Copyright (c) 2016 Uber Technologies, Inc.
//
// Permission is hereby granted, free of charge, to any person obtaining a copy
// of this software and associated documentation files (the "Software"), to deal
// in the Software without restriction, including without limitation the rights
// to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
// copies of the Software, and to permit persons to whom the Software is
// furnished to do so, subject to the following conditions:
//
// The above copyright notice and this permission notice shall be included in
// all copies or substantial portions of the Software.
//
// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
// IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
// FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
// AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
// LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
// OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
// THE SOFTWARE.

package zap

import (
"fmt"
"sort"
"time"

"go.uber.org/zap/zapcore"
)

// SamplingConfig sets a sampling strategy for the logger. Sampling
// caps the global CPU and I/O load that logging puts on your process while
// attempting to preserve a representative subset of your logs.
//
// Values configured here are per-second. See zapcore.Sample for details.
type SamplingConfig struct {
Initial int `json:"initial",yaml:"initial"`
Thereafter int `json:"therafter",yaml:"thereafter"`
}

// Config offers a declarative way to construct a logger.
//
// It doesn't do anything that can't be done with New, Options, and the various
// zapcore.WriteSyncer and zapcore.Facility wrappers, but it's a simpler way to
// toggle common options.
type Config struct {
// Level is the minimum enabled logging level. Note that this is a dynamic
// level, so calling Config.Level.SetLevel will atomically change the log
// level of all loggers descended from this config. The zero value is
// InfoLevel.
Level AtomicLevel `json:"level",yaml:"level"`
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

How about a:

Level Level
AllowLevelChange bool

And defaulting to static levels?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why? The performance overhead is near-zero, and I'd always recommend using a dynamic level.

// Development puts the logger in development mode, which changes the
// behavior of DPanicLevel and takes stacktraces more liberally.
Development bool `json:"development",yaml:"development"`
// DisableCaller stops annotating logs with the calling function's file
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Say more about when it happens if not enabled, always? Only for warn and up?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good point.

// name and line number. By default, all logs are annotated.
DisableCaller bool `json:"disableCaller",yaml:"disableCaller"`
// DisableStacktrace completely disables automatic stacktrace capturing. By
// default, stacktraces are captured for WarnLevel and above logs in
// development and ErrorLevel and above in production.
DisableStacktrace bool `json:"disableStacktrace",yaml:"disableStacktrace"`
// Sampling sets a sampling policy. A nil SamplingConfig disables sampling.
Sampling *SamplingConfig `json:"sampling",yaml:"sampling"`
// Encoding sets the logger's encoding. Valid values are "json" and
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Interesting, I would've expected more of a:

EnableConsole bool // maybe disable instead of enable
DisableStandardErrors bool
FileEncoding string
OutputPaths []string
ErrorOutputPaths []string

The idea being:

  • stdout is always console encoded
  • files are always json encoded
  • errors at least go to stderr, and maybe also a file

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm glad that we can support that setup, but I'm less of a fan of making that part of the quickstart. I remembered discussing it with you and played with it for a while, and I found it pretty jarring. IMO it's just too unusual.

If and when we add new encoders, I'd also like this config struct to support them. Again, I have msgpack in production in mind.

// "console".
Encoding string `json:"encoding",yaml:"encoding"`
// EncoderConfig sets options for the chosen encoder. See
// zapcore.EncoderConfig for details.
EncoderConfig zapcore.EncoderConfig `json:"encoderConfig",yaml:"encoderConfig"`
// OutputPaths is a list of paths to write logging output to. See Open for
// details.
OutputPaths []string `json:"outputPaths",yaml:"outputPaths"`
// ErrorOutputPaths is a list of paths to write internal logger errors to.
// The default is standard error.
ErrorOutputPaths []string `json:"errorOutputPaths",yaml:"errorOutputPaths"`
// InitialFields is a collection of fields to add to the root logger.
InitialFields map[string]interface{} `json:"initialFields",yaml:"initialFields"`
}

// NewProductionConfig is the recommended production configuration. Logging is
// enabled at InfoLevel and above.
//
// It uses a JSON encoder, writes to standard error, and enables sampling.
// Stacktraces are automatically included on logs of ErrorLevel and above.
func NewProductionConfig() Config {
return Config{
Level: DynamicLevel(),
Development: false,
Sampling: &SamplingConfig{
Initial: 100,
Thereafter: 100,
},
Encoding: "json",
EncoderConfig: zapcore.EncoderConfig{
TimeKey: "ts",
LevelKey: "level",
NameKey: "logger",
CallerKey: "caller",
MessageKey: "msg",
StacktraceKey: "stacktrace",
EncodeLevel: zapcore.LowercaseLevelEncoder,
EncodeTime: zapcore.EpochTimeEncoder,
EncodeDuration: zapcore.SecondsDurationEncoder,
},
OutputPaths: []string{"stderr"},
ErrorOutputPaths: []string{"stderr"},
}
}

// NewDevelopmentConfig is a reasonable development configuration. Logging is
// enabled at DebugLevel and above.
//
// It enables development mode, uses a console encoder, writes to standard
// error, and disables sampling. Stacktraces are automatically included on logs
// of WarnLevel and above.
func NewDevelopmentConfig() Config {
dyn := DynamicLevel()
dyn.SetLevel(DebugLevel)

return Config{
Level: dyn,
Development: true,
Encoding: "console",
EncoderConfig: zapcore.EncoderConfig{
// Keys can be anything except the empty string.
TimeKey: "T",
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

These are some surprising defaults imo, but I guess not that the console encoder uses them much?

Apropos of my above remarks, I think I'd still expect a "development" or "staging" deploy to log json to files, and I'd still want to see warn and up on stdout for things like docker logs in production...

Copy link
Contributor Author

@akshayjshah akshayjshah Feb 9, 2017

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The console encoder only cares about empty/non-empty - the actual values aren't used.

Terminology varies, but I'd call anything that's "deployed" a production config. You may have canary, staging, and stable deployments, but it's all production. This config is for use while developers are writing code, running unit tests, and exploring on their local machines.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ahh okay, thanks for clarifying what "development" means.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hm. Can't tell if that's mild sarcasm or not :)

Is there a better name we can use here? Not too late to rename "development" throughout the codebase.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nope, wasn't meant to be sarcastic at all, what I meant:

  • to me, the word "development" in zap is 90% about "will DPanic panic?'
  • I can see a sensible argument for wanting a staging or canary cluster to go either way on that point
  • however I'd always expect a such-deployed cluster to always log to similar channels and encoded the same way as production, the only exception being when running tests, and otherwise "local"/non-deployed development

So I'm not sure if "development" is the best name or not for "non deployed config default", and whether or not we want the ability to vary DPanic's disposition within a canned "deployed config".

LevelKey: "L",
NameKey: "N",
CallerKey: "C",
MessageKey: "M",
StacktraceKey: "S",
EncodeLevel: zapcore.CapitalLevelEncoder,
EncodeTime: zapcore.ISO8601TimeEncoder,
EncodeDuration: zapcore.StringDurationEncoder,
},
OutputPaths: []string{"stderr"},
ErrorOutputPaths: []string{"stderr"},
}
}

// Build constructs a logger from the Config and Options.
func (cfg Config) Build(opts ...Option) (*Logger, error) {
enc, err := cfg.buildEncoder()
if err != nil {
return nil, err
}

sink, errSink, err := cfg.openSinks()
if err != nil {
return nil, err
}

log := New(
zapcore.WriterFacility(enc, sink, cfg.Level),
cfg.buildOptions(errSink)...,
)
if len(opts) > 0 {
log = log.WithOptions(opts...)
}
return log, nil
}

func (cfg Config) buildOptions(errSink zapcore.WriteSyncer) []Option {
opts := []Option{ErrorOutput(errSink)}

if cfg.Development {
opts = append(opts, Development())
}

if !cfg.DisableCaller {
opts = append(opts, AddCaller())
}

stackLevel := ErrorLevel
if cfg.Development {
stackLevel = WarnLevel
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

optional: can move the Development() option append here

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Since we're handling a lot of different things in here, I'd rather handle each of the config struct's fields in a separate little block.

}
if !cfg.DisableStacktrace {
opts = append(opts, AddStacktrace(stackLevel))
}

if cfg.Sampling != nil {
opts = append(opts, WrapFacility(func(fac zapcore.Facility) zapcore.Facility {
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

(just a question) is there a difference between wrapping the facility when passing it into New vs calling WrapFacility?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nope. This was just a bit easier organizationally - otherwise creating the facility needed its own helper method.

return zapcore.Sample(fac, time.Second, int(cfg.Sampling.Initial), int(cfg.Sampling.Thereafter))
}))
}

if len(cfg.InitialFields) > 0 {
fs := make([]zapcore.Field, 0, len(cfg.InitialFields))
keys := make([]string, 0, len(cfg.InitialFields))
for k := range cfg.InitialFields {
keys = append(keys, k)
}
sort.Strings(keys)
for _, k := range keys {
fs = append(fs, Any(k, cfg.InitialFields[k]))
}
opts = append(opts, Fields(fs...))
}

return opts
}

func (cfg Config) openSinks() (zapcore.WriteSyncer, zapcore.WriteSyncer, error) {
sink, err, closeOut := Open(cfg.OutputPaths...)
if err != nil {
closeOut()
return nil, nil, err
}
errSink, err, closeErr := Open(cfg.ErrorOutputPaths...)
if err != nil {
closeOut()
closeErr()
return nil, nil, err
}
return sink, errSink, nil
}
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'd feel mildly better if we could ensure closing happens under errors... but actually doesn't Go setup a finalizer for that by default? Maybe my concerns are baseless?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Certainly possible; I'll just have the Open function also return a close closure. I suppose some people will want to continue operating even if they can't open their log files, so we should be careful.


func (cfg Config) buildEncoder() (zapcore.Encoder, error) {
switch cfg.Encoding {
case "json":
return zapcore.NewJSONEncoder(cfg.EncoderConfig), nil
case "console":
return zapcore.NewConsoleEncoder(cfg.EncoderConfig), nil
}
return nil, fmt.Errorf("unknown encoding %q", cfg.Encoding)
}
87 changes: 87 additions & 0 deletions config_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,87 @@
// Copyright (c) 2016 Uber Technologies, Inc.
//
// Permission is hereby granted, free of charge, to any person obtaining a copy
// of this software and associated documentation files (the "Software"), to deal
// in the Software without restriction, including without limitation the rights
// to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
// copies of the Software, and to permit persons to whom the Software is
// furnished to do so, subject to the following conditions:
//
// The above copyright notice and this permission notice shall be included in
// all copies or substantial portions of the Software.
//
// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
// IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
// FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
// AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
// LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
// OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
// THE SOFTWARE.

package zap

import (
"io/ioutil"
"os"
"testing"

"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)

func TestConfig(t *testing.T) {
tests := []struct {
desc string
cfg Config
expectN int64
expectRe string
}{
{
desc: "production",
cfg: NewProductionConfig(),
expectN: 2 + 100 + 1, // 2 from initial logs, 100 initial sampled logs, 1 from off-by-one in sampler
expectRe: `{"level":"info","caller":".*/go.uber.org/zap/config_test.go:\d+","msg":"info","k":"v","z":"zz"}` + "\n" +
`{"level":"warn","caller":".*/go.uber.org/zap/config_test.go:\d+","msg":"warn","k":"v","z":"zz"}` + "\n",
},
{
desc: "development",
cfg: NewDevelopmentConfig(),
expectN: 3 + 200, // 3 initial logs, all 200 subsequent logs
expectRe: "DEBUG\t.*go.uber.org/zap/config_test.go:" + `\d+` + "\tdebug\t" + `{"k": "v", "z": "zz"}` + "\n" +
"INFO\t.*go.uber.org/zap/config_test.go:" + `\d+` + "\tinfo\t" + `{"k": "v", "z": "zz"}` + "\n" +
"WARN\t.*go.uber.org/zap/config_test.go:" + `\d+` + "\twarn\t" + `{"k": "v", "z": "zz"}` + "\n" +
`goroutine \d+ \[running\]:`,
},
}

for _, tt := range tests {
t.Run(tt.desc, func(t *testing.T) {
temp, err := ioutil.TempFile("", "zap-prod-config-test")
require.NoError(t, err, "Failed to create temp file.")
defer os.Remove(temp.Name())

require.Empty(t, tt.cfg.OutputPaths, "Expected output paths to be unset.")
tt.cfg.OutputPaths = []string{temp.Name()}
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I always feel wary when I see a test fixture mutation...

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Happy to assert that the field isn't set beforehand.

tt.cfg.EncoderConfig.TimeKey = "" // no timestamps in tests
tt.cfg.InitialFields = map[string]interface{}{"z": "zz", "k": "v"}

hook, count := makeCountingHook()
logger, err := tt.cfg.Build(Hooks(hook))
require.NoError(t, err, "Unexpected error constructing logger.")

logger.Debug("debug")
logger.Info("info")
logger.Warn("warn")

byteContents, err := ioutil.ReadAll(temp)
require.NoError(t, err, "Couldn't read log contents from temp file.")
logs := string(byteContents)
assert.Regexp(t, tt.expectRe, logs, "Unexpected log output.")

for i := 0; i < 200; i++ {
logger.Info("sampling")
}
assert.Equal(t, tt.expectN, count.Load(), "Hook called an unexpected number of times.")
})
}
}
17 changes: 17 additions & 0 deletions level.go
Original file line number Diff line number Diff line change
Expand Up @@ -87,3 +87,20 @@ func (lvl AtomicLevel) Level() zapcore.Level {
func (lvl AtomicLevel) SetLevel(l zapcore.Level) {
lvl.l.Store(int32(l))
}

// UnmarshalText unmarshals the text to a DynamicLevel. It uses the same text
// representation as zapcore.Level ("debug", "info", "warn", "error", "dpanic",
// "panic", and "fatal").
func (lvl *AtomicLevel) UnmarshalText(text []byte) error {
var l zapcore.Level
if err := l.UnmarshalText(text); err != nil {
return err
}

if lvl.l == nil {
lvl.l = atomic.NewInt32(int32(l))
return nil
}
lvl.SetLevel(l)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Prefer to:

if lvl.l == nil {
  lvl.l = atomic.NewInt32(int32(l))
} else {
  lvl.SetLevel(l)
}

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍

return nil
}
28 changes: 28 additions & 0 deletions level_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -72,3 +72,31 @@ func TestDynamicLevelMutation(t *testing.T) {
close(proceed)
wg.Wait()
}

func TestDynamicLevelUnmarshalText(t *testing.T) {
tests := []struct {
text string
expect zapcore.Level
err bool
}{
{"debug", DebugLevel, false},
{"info", InfoLevel, false},
{"", InfoLevel, false},
{"warn", WarnLevel, false},
{"error", ErrorLevel, false},
{"dpanic", DPanicLevel, false},
{"panic", PanicLevel, false},
{"fatal", FatalLevel, false},
{"foo", InfoLevel, true},
}

for _, tt := range tests {
var lvl AtomicLevel
if tt.err {
assert.Error(t, lvl.UnmarshalText([]byte(tt.text)), "Expected unmarshaling %q to fail.", tt.text)
} else {
assert.NoError(t, lvl.UnmarshalText([]byte(tt.text)), "Expected unmarshaling %q to succeed.", tt.text)
}
assert.Equal(t, tt.expect, lvl.Level(), "Unexpected level after unmarshaling.")
}
}
Loading