pkg/log/zap: adding helpers for zap logger configuration (#873)

* pkg/log/zap: adding helpers for zap logger configuration

* pkg/scaffold/cmd.go: adding zap logger helper to scaffold

* pkg/log/zap/flags.go: improve zap-devel help text, group sampleValue Set function with others

* pkg/log/zap/flags.go: remove unnecessary import newlines

* pkg/log/zap: remove factory; s/sink/syncer/g

* test/*,commands/operator-sdk/cmd/up/local.go: include flags registered by imported packages

* pkg/log/zap: bump copyright year to 2019

* pkg/scaffold: include flags registered by imported packages

* pkg/(ansible|helm)/flags,commands,test: centralizing zap flagset setup

Moves the zap flagset initialization into the ansible and helm flag
packages so that they are reused in all ansible and helm operator
scenarios (e.g. `up local`, `run`, and the helm binary)

Also reverts parts a previous commit (975eddc) that added flags to the
ansible and helm operators imported by other libraries because it caused
the entire set of "testing" package flags to be added (from
`operator-sdk` dependencies).

* pkg/scaffold/,test/test-framework: whitespace and comment consistency

* images/scorecard-proxy/cmd/proxy/main.go: use configurable zap logger

* pkg/log/zap/flags.go: only allow debug, info, and error

* images/scorecard-proxy/cmd/proxy/main.go: fix imports

* doc/user/logging.md: document zap helpers and flags

Author: joelanford

Gopkg.lock

@@ -17,6 +17,7 @@ package run
 import (
 	"github.com/operator-framework/operator-sdk/pkg/ansible"
 	aoflags "github.com/operator-framework/operator-sdk/pkg/ansible/flags"
+	"github.com/operator-framework/operator-sdk/pkg/log/zap"
 
 	"github.com/spf13/cobra"
 	logf "sigs.k8s.io/controller-runtime/pkg/runtime/log"
@@ -32,7 +33,7 @@ func RunAnsibleCmd() *cobra.Command {
 in a Pod inside a cluster. Developers wanting to run their operator locally
 should use "up local" instead.`,
 		RunE: func(cmd *cobra.Command, args []string) error {
-			logf.SetLogger(logf.ZapLogger(false))
+			logf.SetLogger(zap.Logger())
 
 			return ansible.Run(flags)
 		},

commands/operator-sdk/cmd/run/ansible.go

@@ -17,6 +17,7 @@ package run
 import (
 	"github.com/operator-framework/operator-sdk/pkg/helm"
 	hoflags "github.com/operator-framework/operator-sdk/pkg/helm/flags"
+	"github.com/operator-framework/operator-sdk/pkg/log/zap"
 
 	"github.com/spf13/cobra"
 	logf "sigs.k8s.io/controller-runtime/pkg/runtime/log"
@@ -32,7 +33,7 @@ func RunHelmCmd() *cobra.Command {
 in a Pod inside a cluster. Developers wanting to run their operator locally
 should use "up local" instead.`,
 		RunE: func(cmd *cobra.Command, args []string) error {
-			logf.SetLogger(logf.ZapLogger(false))
+			logf.SetLogger(zap.Logger())
 
 			return helm.Run(flags)
 		},

commands/operator-sdk/cmd/run/helm.go

@@ -31,6 +31,7 @@ import (
 	"github.com/operator-framework/operator-sdk/pkg/helm"
 	hoflags "github.com/operator-framework/operator-sdk/pkg/helm/flags"
 	"github.com/operator-framework/operator-sdk/pkg/k8sutil"
+	"github.com/operator-framework/operator-sdk/pkg/log/zap"
 	"github.com/operator-framework/operator-sdk/pkg/scaffold"
 	sdkVersion "github.com/operator-framework/operator-sdk/version"
 
@@ -136,15 +137,15 @@ func upLocal() error {
 }
 
 func upLocalAnsible() error {
-	logf.SetLogger(logf.ZapLogger(false))
+	logf.SetLogger(zap.Logger())
 	if err := setupOperatorEnv(); err != nil {
 		return err
 	}
 	return ansible.Run(ansibleOperatorFlags)
 }
 
 func upLocalHelm() error {
-	logf.SetLogger(logf.ZapLogger(false))
+	logf.SetLogger(zap.Logger())
 	if err := setupOperatorEnv(); err != nil {
 		return err
 	}

commands/operator-sdk/cmd/up/local.go

@@ -8,11 +8,15 @@ Operators set the logger for all operator logging in [`cmd/manager/main.go`][cod
 
 ```Go
 import (
+	"github.com/operator-framework/operator-sdk/pkg/log/zap"
+	"github.com/spf13/pflag"
 	logf "sigs.k8s.io/controller-runtime/pkg/runtime/log"
 )
 
 func main() {
-  logf.SetLogger(logf.ZapLogger(false))
+  pflag.CommandLine.AddFlagSet(zap.FlagSet())
+  pflag.Parse()
+  logf.SetLogger(zap.Logger())
   log := logf.Log.WithName("cmd")
 
   ...
@@ -25,7 +29,19 @@ func main() {
 
 By using `controller-runtime/pkg/runtime/log`, your logger is propagated through `controller-runtime`. Any logs produced by `controller-runtime` code will be through your logger, and therefore have the same formatting and destination.
 
-In the above example, `logf.ZapLogger()` takes a boolean flag to set development parameters. Passing in `true` will set the logger to log in development mode; debug log statements will trigger, and error log statements will include stack traces.
+### Default zap logger
+
+Operator SDK uses a `zap`-based `logr` backend when scaffolding new projects. To assist with configuring and using this logger, the SDK includes several helper functions.
+
+In the above example, we add the zap flagset to the operator's command line flags with `zap.FlagSet()`, and then set the controller-runtime logger with `zap.Logger()`.
+
+By default, `zap.Logger()` will return a logger that is ready for production use. It uses a JSON encoder, logs starting at the `info` level, and has [sampling][zap_sampling] enabled. To customize the default behavior, users can use the zap flagset and specify flags on the command line. The zap flagset includes the following flags that can be used to configure the logger:
+* `--zap-devel` - Enables the zap development config (changes defaults to console encoder, debug log level, and disables sampling) (default: `false`)
+* `--zap-encoder` string - Sets the zap log encoding (`json` or `console`)
+* `--zap-level` string - Sets the zap log level (`debug`, `info`, or `error`)
+* `--zap-sample` - Enables zap's sampling mode
+
+**NOTE:** Although the `logr` interface supports multiple debug levels (e.g. `log.V(1).Info()`, `log.V(2).Info()`, etc.), zap supports only a single debug level with `log.V(1).Info()`. Log statements with higher debug levels will not be printed with the zap's `logr` backend.
 
 ## Creating a structured log statement
 
@@ -102,4 +118,5 @@ If you do not want to use `logr` as your logging tool, you can remove `logr`-spe
 [godoc_logr_logger]:https://godoc.org/github.com/go-logr/logr#Logger
 [site_struct_logging]:https://www.client9.com/structured-logging-in-golang/
 [code_memcached_controller]:../../example/memcached-operator/memcached_controller.go.tmpl
-[code_set_logger]:https://github.com/operator-framework/operator-sdk/blob/948139171fff0e802c9e68f87cb95939941772ef/pkg/scaffold/cmd.go#L68-L72
+[code_set_logger]:https://github.com/operator-framework/operator-sdk/blob/ecd02000616f11303f1adecd3d4ceb4a8561a9ec/pkg/scaffold/cmd.go#L90-L94
+[zap_sampling]:https://github.com/uber-go/zap/blob/master/FAQ.md#why-sample-application-logs

doc/user/logging.md

@@ -15,22 +15,25 @@
 package main
 
 import (
-	"flag"
 	"os"
 
 	proxy "github.com/operator-framework/operator-sdk/pkg/ansible/proxy"
 	"github.com/operator-framework/operator-sdk/pkg/ansible/proxy/controllermap"
 	"github.com/operator-framework/operator-sdk/pkg/k8sutil"
+	"github.com/operator-framework/operator-sdk/pkg/log/zap"
 
 	log "github.com/sirupsen/logrus"
+	"github.com/spf13/pflag"
 	"sigs.k8s.io/controller-runtime/pkg/client/config"
 	"sigs.k8s.io/controller-runtime/pkg/manager"
 	logf "sigs.k8s.io/controller-runtime/pkg/runtime/log"
 )
 
 func main() {
-	flag.Parse()
-	logf.SetLogger(logf.ZapLogger(false))
+	pflag.CommandLine.AddFlagSet(zap.FlagSet())
+	pflag.Parse()
+
+	logf.SetLogger(zap.Logger())
 
 	namespace, found := os.LookupEnv(k8sutil.WatchNamespaceEnvVar)
 	if found {

images/scorecard-proxy/cmd/proxy/main.go

@@ -16,6 +16,7 @@ package flags
 
 import (
 	"github.com/operator-framework/operator-sdk/pkg/internal/flags"
+	"github.com/operator-framework/operator-sdk/pkg/log/zap"
 	"github.com/spf13/pflag"
 )
 
@@ -29,5 +30,6 @@ type AnsibleOperatorFlags struct {
 func AddTo(flagSet *pflag.FlagSet, helpTextPrefix ...string) *AnsibleOperatorFlags {
 	aof := &AnsibleOperatorFlags{}
 	aof.WatchFlags.AddTo(flagSet, helpTextPrefix...)
+	flagSet.AddFlagSet(zap.FlagSet())
 	return aof
 }

pkg/ansible/flags/flag.go

@@ -16,6 +16,7 @@ package flags
 
 import (
 	"github.com/operator-framework/operator-sdk/pkg/internal/flags"
+	"github.com/operator-framework/operator-sdk/pkg/log/zap"
 	"github.com/spf13/pflag"
 )
 
@@ -29,5 +30,6 @@ type HelmOperatorFlags struct {
 func AddTo(flagSet *pflag.FlagSet, helpTextPrefix ...string) *HelmOperatorFlags {
 	hof := &HelmOperatorFlags{}
 	hof.WatchFlags.AddTo(flagSet, helpTextPrefix...)
+	flagSet.AddFlagSet(zap.FlagSet())
 	return hof
 }

pkg/helm/flags/flag.go

@@ -0,0 +1,131 @@
+// Copyright 2019 The Operator-SDK Authors
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package zap
+
+import (
+	"fmt"
+	"strconv"
+	"strings"
+
+	"github.com/spf13/pflag"
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+)
+
+var (
+	zapFlagSet *pflag.FlagSet
+
+	development bool
+	encoderVal  encoderValue
+	levelVal    levelValue
+	sampleVal   sampleValue
+)
+
+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.Var(&encoderVal, "zap-encoder", "Zap log encoding ('json' or 'console')")
+	zapFlagSet.Var(&levelVal, "zap-level", "Zap log level (one of 'debug', 'info', 'error')")
+	zapFlagSet.Var(&sampleVal, "zap-sample", "Enable zap log sampling")
+}
+
+func FlagSet() *pflag.FlagSet {
+	return zapFlagSet
+}
+
+type encoderValue struct {
+	set     bool
+	encoder zapcore.Encoder
+	str     string
+}
+
+func (v *encoderValue) Set(e string) error {
+	v.set = true
+	switch e {
+	case "json":
+		v.encoder = jsonEncoder()
+	case "console":
+		v.encoder = consoleEncoder()
+	default:
+		return fmt.Errorf("unknown encoder \"%s\"", e)
+	}
+	v.str = e
+	return nil
+}
+
+func (v encoderValue) String() string {
+	return v.str
+}
+
+func (v encoderValue) Type() string {
+	return "encoder"
+}
+
+func jsonEncoder() zapcore.Encoder {
+	encoderConfig := zap.NewProductionEncoderConfig()
+	return zapcore.NewJSONEncoder(encoderConfig)
+}
+
+func consoleEncoder() zapcore.Encoder {
+	encoderConfig := zap.NewDevelopmentEncoderConfig()
+	return zapcore.NewConsoleEncoder(encoderConfig)
+}
+
+type levelValue struct {
+	set   bool
+	level zapcore.Level
+}
+
+func (v *levelValue) Set(l string) error {
+	v.set = true
+	lower := strings.ToLower(l)
+	switch lower {
+	case "debug", "info", "error":
+		return v.level.Set(l)
+	}
+	return fmt.Errorf("invalid log level \"%s\"", l)
+}
+
+func (v levelValue) String() string {
+	return v.level.String()
+}
+
+func (v levelValue) Type() string {
+	return "level"
+}
+
+type sampleValue struct {
+	set    bool
+	sample bool
+}
+
+func (v *sampleValue) Set(s string) error {
+	var err error
+	v.set = true
+	v.sample, err = strconv.ParseBool(s)
+	return err
+}
+
+func (v sampleValue) String() string {
+	return strconv.FormatBool(v.sample)
+}
+
+func (v sampleValue) IsBoolFlag() bool {
+	return true
+}
+
+func (v sampleValue) Type() string {
+	return "sample"
+}

pkg/log/zap/flags.go

@@ -0,0 +1,84 @@
+// Copyright 2019 The Operator-SDK Authors
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package zap
+
+import (
+	"io"
+	"os"
+	"time"
+
+	"github.com/go-logr/logr"
+	"github.com/go-logr/zapr"
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+	logf "sigs.k8s.io/controller-runtime/pkg/runtime/log"
+)
+
+func Logger() logr.Logger {
+	return LoggerTo(os.Stderr)
+}
+
+func LoggerTo(destWriter io.Writer) logr.Logger {
+	syncer := zapcore.AddSync(destWriter)
+	conf := getConfig(destWriter)
+
+	conf.encoder = &logf.KubeAwareEncoder{Encoder: conf.encoder, Verbose: conf.level.Level() < 0}
+	if conf.sample {
+		conf.opts = append(conf.opts, zap.WrapCore(func(core zapcore.Core) zapcore.Core {
+			return zapcore.NewSampler(core, time.Second, 100, 100)
+		}))
+	}
+	conf.opts = append(conf.opts, zap.AddCallerSkip(1), zap.ErrorOutput(syncer))
+	log := zap.New(zapcore.NewCore(conf.encoder, syncer, conf.level))
+	log = log.WithOptions(conf.opts...)
+	return zapr.NewLogger(log)
+}
+
+type config struct {
+	encoder zapcore.Encoder
+	level   zap.AtomicLevel
+	sample  bool
+	opts    []zap.Option
+}
+
+func getConfig(destWriter io.Writer) config {
+	var c config
+
+	// Set the defaults depending on the log mode (development vs. production)
+	if development {
+		c.encoder = consoleEncoder()
+		c.level = zap.NewAtomicLevelAt(zap.DebugLevel)
+		c.opts = append(c.opts, zap.Development(), zap.AddStacktrace(zap.ErrorLevel))
+		c.sample = false
+	} else {
+		c.encoder = jsonEncoder()
+		c.level = zap.NewAtomicLevelAt(zap.InfoLevel)
+		c.opts = append(c.opts, zap.AddStacktrace(zap.WarnLevel))
+		c.sample = true
+	}
+
+	// Override the defaults if the flags were set explicitly on the command line
+	if encoderVal.set {
+		c.encoder = encoderVal.encoder
+	}
+	if levelVal.set {
+		c.level = zap.NewAtomicLevelAt(levelVal.level)
+	}
+	if sampleVal.set {
+		c.sample = sampleVal.sample
+	}
+
+	return c
+}