Skip to content

Commit

Permalink
log: add option to set the minimum level of zap stack trace generation
Browse files Browse the repository at this point in the history
For some of our public operators, we would like to keep logs clean and tidy
to improve readability/investigations for our customers
  • Loading branch information
vboulineau committed Dec 13, 2019
1 parent 8adf8db commit 1cc229f
Show file tree
Hide file tree
Showing 7 changed files with 141 additions and 36 deletions.
1 change: 1 addition & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@

- Added new `--bundle` flag to the `operator-sdk scorecard` command to support bundle validation testing using the validation API (https://github.com/operator-framework/api). ([#1916](https://github.com/operator-framework/operator-sdk/pull/1916)
- Added new `log` field to the `operator-sdk scorecard` v1alpha2 output to support tests that produce logging. ([#1916](https://github.com/operator-framework/operator-sdk/pull/1916)
- Add a new option to set the minimum loglevel that triggers stack trace generation in logs (`--zap-stacktrace-level`) ([#2319](https://github.com/operator-framework/operator-sdk/pull/2319))
- Added new `bundle validation` test to the `operator-sdk scorecard` OLM tests. ([#1916](https://github.com/operator-framework/operator-sdk/pull/1916)

### Changed
Expand Down
3 changes: 2 additions & 1 deletion doc/cli/operator-sdk_run_ansible.md
Original file line number Diff line number Diff line change
Expand Up @@ -21,10 +21,11 @@ operator-sdk run ansible [flags]
--max-workers int Maximum number of workers to use. Overridden by environment variable. (default 1)
--reconcile-period duration Default reconcile period for controllers (default 1m0s)
--watches-file string Path to the watches file to use (default "./watches.yaml")
--zap-devel Enable zap development mode (changes defaults to console encoder, debug log level, and disables sampling)
--zap-devel Enable zap development mode (changes defaults to console encoder, debug log level, disables sampling and stacktrace from 'warning' level)
--zap-encoder encoder Zap log encoding ('json' or 'console')
--zap-level level Zap log level (one of 'debug', 'info', 'error' or any integer value > 0) (default info)
--zap-sample sample Enable zap log sampling. Sampling will be disabled for integer log levels > 1
--zap-stacktrace-level level Set the minimum log level that triggers stacktrace generation (default error)
--zap-time-encoding timeEncoding Sets the zap time format ('epoch', 'millis', 'nano', or 'iso8601') (default )
```

Expand Down
3 changes: 2 additions & 1 deletion doc/cli/operator-sdk_run_helm.md
Original file line number Diff line number Diff line change
Expand Up @@ -18,10 +18,11 @@ operator-sdk run helm [flags]
-h, --help help for helm
--reconcile-period duration Default reconcile period for controllers (default 1m0s)
--watches-file string Path to the watches file to use (default "./watches.yaml")
--zap-devel Enable zap development mode (changes defaults to console encoder, debug log level, and disables sampling)
--zap-devel Enable zap development mode (changes defaults to console encoder, debug log level, disables sampling and stacktrace from 'warning' level)
--zap-encoder encoder Zap log encoding ('json' or 'console')
--zap-level level Zap log level (one of 'debug', 'info', 'error' or any integer value > 0) (default info)
--zap-sample sample Enable zap log sampling. Sampling will be disabled for integer log levels > 1
--zap-stacktrace-level level Set the minimum log level that triggers stacktrace generation (default error)
--zap-time-encoding timeEncoding Sets the zap time format ('epoch', 'millis', 'nano', or 'iso8601') (default )
```

Expand Down
1 change: 1 addition & 0 deletions doc/user/logging.md
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,7 @@ By default, `zap.Logger()` will return a logger that is ready for production use
* `--zap-encoder` string - Sets the zap log encoding (`json` or `console`)
* `--zap-level` string or integer - Sets the zap log level (`debug`, `info`, `error`, or an integer value greater than 0). If 4 or greater the verbosity of client-go will be set to this level.
* `--zap-sample` - Enables zap's sampling mode. Sampling will be disabled for integer log levels greater than 1.
* `--zap-stacktrace-level` - Set the minimum log level that triggers stacktrace generation (default: `error`)
* `--zap-time-encoding` string - Sets the zap time format (`epoch`, `millis`, `nano`, or `iso8601`)

### A simple example
Expand Down
81 changes: 60 additions & 21 deletions pkg/log/zap/flags.go
Original file line number Diff line number Diff line change
Expand Up @@ -34,15 +34,17 @@ var (
levelVal levelValue
sampleVal sampleValue
timeEncodingVal timeEncodingValue
stacktraceLevel stackLevelValue
)

func init() {
zapFlagSet = pflag.NewFlagSet("zap", pflag.ExitOnError)
zapFlagSet.BoolVar(&development, "zap-devel", false, "Enable zap development mode (changes defaults to console encoder, debug log level, and disables sampling)")
zapFlagSet.BoolVar(&development, "zap-devel", false, "Enable zap development mode (changes defaults to console encoder, debug log level, disables sampling and stacktrace from 'warning' level)")
zapFlagSet.Var(&encoderVal, "zap-encoder", "Zap log encoding ('json' or 'console')")
zapFlagSet.Var(&levelVal, "zap-level", "Zap log level (one of 'debug', 'info', 'error' or any integer value > 0)")
zapFlagSet.Var(&sampleVal, "zap-sample", "Enable zap log sampling. Sampling will be disabled for integer log levels > 1")
zapFlagSet.Var(&timeEncodingVal, "zap-time-encoding", "Sets the zap time format ('epoch', 'millis', 'nano', or 'iso8601')")
zapFlagSet.Var(&stacktraceLevel, "zap-stacktrace-level", "Set the minimum log level that triggers stacktrace generation")
}

// FlagSet - The zap logging flagset.
Expand Down Expand Up @@ -103,27 +105,11 @@ type levelValue struct {

func (v *levelValue) Set(l string) error {
v.set = true
lower := strings.ToLower(l)
var lvl int
switch lower {
case "debug":
lvl = -1
case "info":
lvl = 0
case "error":
lvl = 2
default:
i, err := strconv.Atoi(lower)
if err != nil {
return fmt.Errorf("invalid log level \"%s\"", l)
}

if i > 0 {
lvl = -1 * i
} else {
return fmt.Errorf("invalid log level \"%s\"", l)
}
lvl, err := intLogLevel(l)
if err != nil {
return err
}

v.level = zapcore.Level(int8(lvl))
// If log level is greater than debug, set glog/klog level to that level.
if lvl < -3 {
Expand All @@ -145,6 +131,59 @@ func (v levelValue) Type() string {
return "level"
}

type stackLevelValue struct {
set bool
level zapcore.Level
}

func (v *stackLevelValue) Set(l string) error {
v.set = true
lvl, err := intLogLevel(l)
if err != nil {
return err
}

v.level = zapcore.Level(int8(lvl))
return nil
}

func (v stackLevelValue) String() string {
if v.set {
return v.level.String()
}

return "error"
}

func (v stackLevelValue) Type() string {
return "level"
}

func intLogLevel(l string) (int, error) {
lower := strings.ToLower(l)
var lvl int
switch lower {
case "debug":
lvl = -1
case "info":
lvl = 0
case "error":
lvl = 2
default:
i, err := strconv.Atoi(lower)
if err != nil {
return lvl, fmt.Errorf("invalid log level \"%s\"", l)
}

if i > 0 {
lvl = -1 * i
} else {
return lvl, fmt.Errorf("invalid log level \"%s\"", l)
}
}
return lvl, nil
}

type sampleValue struct {
set bool
sample bool
Expand Down
19 changes: 13 additions & 6 deletions pkg/log/zap/logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -51,10 +51,11 @@ func createLogger(conf config, destWriter io.Writer) logr.Logger {
}

type config struct {
encoder zapcore.Encoder
level zap.AtomicLevel
sample bool
opts []zap.Option
encoder zapcore.Encoder
level zap.AtomicLevel
opts []zap.Option
stackTraceLevel zapcore.Level
sample bool
}

func getConfig() config {
Expand All @@ -66,16 +67,22 @@ func getConfig() config {
if development {
newEncoder = newConsoleEncoder
c.level = zap.NewAtomicLevelAt(zap.DebugLevel)
c.opts = append(c.opts, zap.Development(), zap.AddStacktrace(zap.ErrorLevel))
c.opts = append(c.opts, zap.Development())
c.sample = false
c.stackTraceLevel = zap.WarnLevel
} else {
newEncoder = newJSONEncoder
c.level = zap.NewAtomicLevelAt(zap.InfoLevel)
c.opts = append(c.opts, zap.AddStacktrace(zap.WarnLevel))
c.sample = true
c.stackTraceLevel = zap.ErrorLevel
}

// Override the defaults if the flags were set explicitly on the command line
if stacktraceLevel.set {
c.stackTraceLevel = stacktraceLevel.level
}
c.opts = append(c.opts, zap.AddStacktrace(c.stackTraceLevel))

var ecfs []encoderConfigFunc
if encoderVal.set {
newEncoder = encoderVal.newEncoder
Expand Down
69 changes: 62 additions & 7 deletions pkg/log/zap/logger_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -28,13 +28,14 @@ import (
func TestGetConfig(t *testing.T) {
var opts []zap.Option
type fields struct {
name string
inEncoder *encoderValue
inLevel *levelValue
inSample *sampleValue
inTimeEncoding *timeEncodingValue
expected *config
inDevel bool
name string
inEncoder *encoderValue
inLevel *levelValue
inSample *sampleValue
inTimeEncoding *timeEncodingValue
expected *config
inDevel bool
inStackTraceLevel *stackLevelValue
}
tests := []struct {
name string
Expand All @@ -56,6 +57,9 @@ func TestGetConfig(t *testing.T) {
inTimeEncoding: &timeEncodingValue{
set: false,
},
inStackTraceLevel: &stackLevelValue{
set: false,
},
expected: &config{
encoder: newConsoleEncoder(),
level: zap.NewAtomicLevelAt(zap.DebugLevel),
Expand All @@ -78,6 +82,9 @@ func TestGetConfig(t *testing.T) {
inTimeEncoding: &timeEncodingValue{
set: false,
},
inStackTraceLevel: &stackLevelValue{
set: false,
},
expected: &config{
encoder: newJSONEncoder(),
level: zap.NewAtomicLevelAt(zap.InfoLevel),
Expand All @@ -101,6 +108,9 @@ func TestGetConfig(t *testing.T) {
inTimeEncoding: &timeEncodingValue{
set: false,
},
inStackTraceLevel: &stackLevelValue{
set: false,
},
expected: &config{
encoder: newConsoleEncoder(),
level: zap.NewAtomicLevelAt(zap.InfoLevel),
Expand All @@ -124,6 +134,9 @@ func TestGetConfig(t *testing.T) {
inTimeEncoding: &timeEncodingValue{
set: false,
},
inStackTraceLevel: &stackLevelValue{
set: false,
},
expected: &config{
encoder: newJSONEncoder(),
level: zap.NewAtomicLevelAt(zap.ErrorLevel),
Expand All @@ -147,6 +160,9 @@ func TestGetConfig(t *testing.T) {
inTimeEncoding: &timeEncodingValue{
set: false,
},
inStackTraceLevel: &stackLevelValue{
set: false,
},
expected: &config{
encoder: newJSONEncoder(),
level: zap.NewAtomicLevelAt(zapcore.Level(-10)),
Expand All @@ -170,6 +186,9 @@ func TestGetConfig(t *testing.T) {
inTimeEncoding: &timeEncodingValue{
set: false,
},
inStackTraceLevel: &stackLevelValue{
set: false,
},
expected: &config{
encoder: newJSONEncoder(),
level: zap.NewAtomicLevelAt(zap.InfoLevel),
Expand All @@ -194,6 +213,9 @@ func TestGetConfig(t *testing.T) {
inTimeEncoding: &timeEncodingValue{
set: false,
},
inStackTraceLevel: &stackLevelValue{
set: false,
},
expected: &config{
encoder: newJSONEncoder(),
level: zap.NewAtomicLevelAt(zapcore.Level(-10)),
Expand All @@ -217,13 +239,45 @@ func TestGetConfig(t *testing.T) {
set: true,
timeEncoder: zapcore.EpochMillisTimeEncoder,
},
inStackTraceLevel: &stackLevelValue{
set: false,
},
expected: &config{
encoder: newJSONEncoder(withTimeEncoding(zapcore.EpochMillisTimeEncoder)),
level: zap.NewAtomicLevelAt(zap.InfoLevel),
opts: append(opts, zap.AddStacktrace(zap.WarnLevel)),
sample: true,
}},
},
{
name: "set stacktrace generation on 'panic' level only",
fields: fields{
inDevel: false,
inEncoder: &encoderValue{
set: false,
},
inLevel: &levelValue{
set: true,
level: zapcore.Level(-10),
},
inSample: &sampleValue{
set: true,
sample: true,
},
inTimeEncoding: &timeEncodingValue{
set: false,
},
inStackTraceLevel: &stackLevelValue{
set: true,
level: zapcore.Level(zapcore.PanicLevel),
},
expected: &config{
encoder: newJSONEncoder(),
level: zap.NewAtomicLevelAt(zapcore.Level(-10)),
opts: append(opts, zap.AddStacktrace(zap.PanicLevel)),
sample: false,
}},
},
}

entry := zapcore.Entry{
Expand All @@ -246,6 +300,7 @@ func TestGetConfig(t *testing.T) {
levelVal = *tc.fields.inLevel
sampleVal = *tc.fields.inSample
timeEncodingVal = *tc.fields.inTimeEncoding
stacktraceLevel = *tc.fields.inStackTraceLevel

cfg := getConfig()
assert.Equal(t, tc.fields.expected.level, cfg.level)
Expand Down

0 comments on commit 1cc229f

Please sign in to comment.