Migrate to zap logger

Gopkg.toml

@@ -21,7 +21,9 @@
 
 ignored = ["k8s.io/client-go/pkg/api/v1"]
 [[constraint]]
+ revision = "ad18aa91a01e5a7a4d312d16528a181979a23c62"
  name = "github.com/golang/glog"
+ source = "github.com/prydie/glog"
 
 [[constraint]]
  name = "github.com/kubernetes-incubator/external-storage"

Makefile

@@ -68,7 +68,14 @@ build: ${DIR}/${BIN}
 
 ${DIR}/${BIN}: ${GO_SRC}
 	mkdir -p ${DIR}
-	GOOS=${GOOS} GOARCH=${GOARCH} CGO_ENABLED=0 go build -i -v -ldflags '-extldflags "-static"' -o $@ ./cmd/
+	GOOS=${GOOS} \
+	GOARCH=${GOARCH} \
+	CGO_ENABLED=0 \
+	go build \
+	-i \
+	-v \
+	-ldflags="-s -w -X main.version=${VERSION} -X main.build=${BUILD} -extldflags -static" \
+	-o $@ ./cmd/
 
 .PHONY: image
 image: build

cmd/main.go

@@ -21,15 +21,17 @@ import (
 	"syscall"
 	"time"
 
-	"github.com/golang/glog"
-	"github.com/kubernetes-incubator/external-storage/lib/controller"
-	"github.com/oracle/oci-volume-provisioner/pkg/provisioner/core"
-	"github.com/oracle/oci-volume-provisioner/pkg/signals"
-
 	"k8s.io/apimachinery/pkg/api/resource"
 	"k8s.io/client-go/informers"
 	"k8s.io/client-go/kubernetes"
 	"k8s.io/client-go/tools/clientcmd"
+
+	"github.com/kubernetes-incubator/external-storage/lib/controller"
+	"go.uber.org/zap"
+
+	"github.com/oracle/oci-volume-provisioner/pkg/logging"
+	"github.com/oracle/oci-volume-provisioner/pkg/provisioner/core"
+	"github.com/oracle/oci-volume-provisioner/pkg/signals"
 )
 
 const (
@@ -43,6 +45,10 @@ const (
 	termLimit                 = controller.DefaultTermLimit
 )
 
+// version/build is set at build time to the version of the provisioner being built.
+var version string
+var build string
+
 // informerResyncPeriod computes the time interval a shared informer waits
 // before resyncing with the API server.
 func informerResyncPeriod(minResyncPeriod time.Duration) func() time.Duration {
@@ -54,13 +60,20 @@ func informerResyncPeriod(minResyncPeriod time.Duration) func() time.Duration {
 
 func main() {
 	syscall.Umask(0)
-	rand.Seed(time.Now().Unix())
+
+	log := logging.Logger()
+	defer log.Sync()
+	zap.ReplaceGlobals(log)
+
 	kubeconfig := flag.String("kubeconfig", "", "Path to Kubeconfig file with authorization and master location information.")
 	volumeRoundingEnabled := flag.Bool("rounding-enabled", true, "When enabled volumes will be rounded up if less than 'minVolumeSizeMB'")
 	minVolumeSize := flag.String("min-volume-size", "50Gi", "The minimum size for a block volume. By default OCI only supports block volumes > 50GB")
 	master := flag.String("master", "", "The address of the Kubernetes API server (overrides any value in kubeconfig).")
 	flag.Parse()
-	flag.Set("logtostderr", "true")
+
+	logger := log.Sugar()
+
+	logger.With("version", version, "build", build).Info("oci-volume-provisioner")
 
 	// Set up signals so we handle the shutdown signal gracefully.
 	stopCh := signals.SetupSignalHandler()
@@ -69,25 +82,25 @@ func main() {
 	// to use to communicate with Kubernetes
 	config, err := clientcmd.BuildConfigFromFlags(*master, *kubeconfig)
 	if err != nil {
-		glog.Fatalf("Failed to load config: %v", err)
+		logger.With(zap.Error(err)).Fatal("Failed to load config")
 	}
 
 	clientset, err := kubernetes.NewForConfig(config)
 	if err != nil {
-		glog.Fatalf("Failed to create client: %v", err)
+		logger.With(zap.Error(err)).Fatal("Failed to create Kubernetes client")
 	}
 
 	// The controller needs to know what the server version is because out-of-tree
 	// provisioners aren't officially supported until 1.5
 	serverVersion, err := clientset.Discovery().ServerVersion()
 	if err != nil {
-		glog.Fatalf("Error getting server version: %v", err)
+		logger.With(zap.Error(err)).Fatal("Failed to get kube-apiserver version")
 	}
 
 	// TODO (owainlewis) ensure this is clearly documented
 	nodeName := os.Getenv("NODE_NAME")
 	if nodeName == "" {
-		glog.Fatal("env variable NODE_NAME must be set so that this provisioner can identify itself")
+		logger.Fatal("env variable NODE_NAME must be set so that this provisioner can identify itself")
 	}
 
 	// Decides what type of provider to deploy, either block or fss
@@ -96,21 +109,23 @@ func main() {
 		provisionerType = core.ProvisionerNameDefault
 	}
 
-	glog.Infof("Starting volume provisioner in %s mode", provisionerType)
+	logger = logger.With("provisionerType", provisionerType)
+	logger.Infof("Starting volume provisioner in %q mode", provisionerType)
 
 	sharedInformerFactory := informers.NewSharedInformerFactory(clientset, informerResyncPeriod(minResyncPeriod)())
 
 	volumeSizeLowerBound, err := resource.ParseQuantity(*minVolumeSize)
 	if err != nil {
-		glog.Fatalf("Cannot parse volume size %s", *minVolumeSize)
+		logger.With(zap.Error(err), "minimumVolumeSize", *minVolumeSize).Fatal("Failed to parse minimum volume size")
 	}
 
 	// Create the provisioner: it implements the Provisioner interface expected by
 	// the controller
-	ociProvisioner, err := core.NewOCIProvisioner(clientset, sharedInformerFactory.Core().V1().Nodes(), provisionerType, nodeName, *volumeRoundingEnabled, volumeSizeLowerBound)
+	ociProvisioner, err := core.NewOCIProvisioner(logger, clientset, sharedInformerFactory.Core().V1().Nodes(), provisionerType, nodeName, *volumeRoundingEnabled, volumeSizeLowerBound)
 	if err != nil {
-		glog.Fatalf("Cannot create volume provisioner %v", err)
+		logger.With(zap.Error(err)).Fatal("Cannot create volume provisioner.")
 	}
+
 	// Start the provision controller which will dynamically provision oci
 	// PVs
 	pc := controller.NewProvisionController(
@@ -132,7 +147,7 @@ func main() {
 	// We block waiting for Ready() after the shared informer factory has
 	// started so we don't deadlock waiting for caches to sync.
 	if err := ociProvisioner.Ready(stopCh); err != nil {
-		glog.Fatalf("Failed to start volume provisioner: %v", err)
+		logger.With(zap.Error(err)).Fatal("Failed to start volume provisioner")
 	}
 
 	pc.Run(stopCh)

pkg/logging/logging.go

@@ -0,0 +1,135 @@
+// Copyright (c) 2017, Oracle and/or its affiliates. All rights reserved.
+//
+// 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 logging
+
+import (
+	"flag"
+	"os"
+	"strings"
+	"sync"
+
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+	lumberjack "gopkg.in/natefinch/lumberjack.v2"
+)
+
+var (
+	lvl         = zapcore.InfoLevel
+	logJSON     = false
+	logfilePath = ""
+	config      *zap.Config
+	mu          sync.Mutex
+)
+
+func init() {
+	flag.Var(&lvl, "log-level", "Adjusts the level of the logs that will be omitted.")
+	flag.BoolVar(&logJSON, "log-json", logJSON, "Log in json format.")
+	flag.StringVar(&logfilePath, "logfile-path", "", "If specified, write log messages to a file at this path.")
+}
+
+// Options holds the zap logger configuration.
+type Options struct {
+	LogLevel *zapcore.Level
+	Config   *zap.Config
+}
+
+// Level gets the current log level.
+func Level() *zap.AtomicLevel {
+	return &config.Level
+}
+
+// Logger builds a new logger based on the given flags.
+func Logger() *zap.Logger {
+	mu.Lock()
+	defer mu.Unlock()
+
+	var cfg zap.Config
+
+	if !logJSON {
+		cfg = zap.NewDevelopmentConfig()
+	} else {
+		cfg = zap.NewProductionConfig()
+	}
+
+	// Extract log fields from environment variables.
+	envFields := FieldsFromEnv(os.Environ())
+
+	options := []zap.Option{
+		zap.AddStacktrace(zapcore.FatalLevel),
+		zap.WrapCore(func(c zapcore.Core) zapcore.Core {
+			return c.With(envFields)
+		}),
+	}
+
+	if len(logfilePath) > 0 {
+		w := zapcore.AddSync(&lumberjack.Logger{
+			Filename:   logfilePath,
+			MaxSize:    10, // megabytes
+			MaxBackups: 3,
+			MaxAge:     28, // days
+		})
+		var enc zapcore.Encoder
+		if logJSON {
+			enc = zapcore.NewJSONEncoder(cfg.EncoderConfig)
+		} else {
+			enc = zapcore.NewConsoleEncoder(cfg.EncoderConfig)
+		}
+		core := zapcore.NewCore(enc, w, lvl)
+		options = append(options, zap.WrapCore(func(zapcore.Core) zapcore.Core {
+			return core
+		}))
+	}
+
+	if config == nil {
+		config = &cfg
+		config.Level.SetLevel(lvl)
+		config.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
+	}
+
+	logger, err := config.Build(
+		// We handle this via errors package for 99% of the stuff so only
+		// enable this at the fatal/panic level.
+		options...,
+	)
+	if err != nil {
+		panic(err)
+	}
+
+	return logger
+}
+
+// FieldsFromEnv extracts log fields from environment variables.
+// If an environment variable starts with LOG_FIELD_, the suffix is extracted
+// and split on =. The first part is used for the name and the second for the
+// value.
+// For example, LOG_FIELD_foo=bar would result in a field named "foo" with the
+// value "bar".
+func FieldsFromEnv(env []string) []zapcore.Field {
+	const logfieldPrefix = "LOG_FIELD_"
+
+	fields := []zapcore.Field{}
+	for _, s := range env {
+		if !strings.HasPrefix(s, logfieldPrefix) || len(s) < (len(logfieldPrefix)+1) {
+			continue
+		}
+		s = s[len(logfieldPrefix):]
+		parts := strings.SplitN(s, "=", 2)
+		if len(parts) != 2 {
+			continue
+		}
+		fields = append(fields, zap.String(parts[0], parts[1]))
+	}
+	return fields
+}