Replace glog with zap

Author: prydie

cmd/oci-cloud-controller-manager/main.go

@@ -21,8 +21,8 @@ import (
 	"os"
 	"time"
 
-	"github.com/golang/glog"
 	"github.com/spf13/pflag"
+	"go.uber.org/zap"
 
 	utilflag "k8s.io/apiserver/pkg/util/flag"
 	"k8s.io/apiserver/pkg/util/logs"
@@ -50,7 +50,7 @@ func main() {
 	logs.InitLogs()
 	defer logs.FlushLogs()
 
-	glog.V(1).Infof("oci-cloud-controller-manager version: %s (%s)", version, build)
+	zap.S().Infof("oci-cloud-controller-manager version: %s (%s)", version, build)
 
 	if err := command.Execute(); err != nil {
 		fmt.Fprintf(os.Stderr, "error: %v\n", err)

pkg/log/log.go

@@ -0,0 +1,90 @@
+// Copyright 2018 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 log
+
+import (
+	"flag"
+	"fmt"
+	"sync"
+
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+)
+
+var (
+	lvlString     = "info"
+	logJSON       = false
+	config        *zap.Config
+	mu            sync.Mutex
+	glogVerbosity string
+)
+
+func init() {
+	flag.StringVar(&lvlString, "log-level", lvlString, "Adjusts the level of the logs that will be omitted.")
+	flag.BoolVar(&logJSON, "log-json", logJSON, "Log in json format.")
+	_ = flag.String("v", "", "For glog backwards compat. Does nothing.")
+}
+
+// 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
+}
+
+func levelFromString(level string) (*zapcore.Level, error) {
+	var zapLevel zapcore.Level
+	if err := zapLevel.UnmarshalText([]byte(level)); err != nil {
+		return nil, fmt.Errorf("invalid logging level: %v", level)
+	}
+	return &zapLevel, nil
+}
+
+// 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()
+	}
+
+	if config == nil {
+		config = &cfg
+		if level, err := levelFromString(lvlString); err == nil {
+			config.Level = zap.NewAtomicLevelAt(*level)
+		}
+		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.
+		zap.AddStacktrace(zapcore.FatalLevel),
+	)
+	if err != nil {
+		panic(err)
+	}
+
+	return logger
+}

pkg/oci/ccm.go

@@ -23,10 +23,10 @@ import (
 
 	"time"
 
-	"github.com/golang/glog"
 	"github.com/oracle/oci-go-sdk/common"
 	"github.com/oracle/oci-go-sdk/common/auth"
 	"github.com/pkg/errors"
+	"go.uber.org/zap"
 
 	utilruntime "k8s.io/apimachinery/pkg/util/runtime"
 	wait "k8s.io/apimachinery/pkg/util/wait"
@@ -38,6 +38,7 @@ import (
 	cloudprovider "k8s.io/kubernetes/pkg/cloudprovider"
 	controller "k8s.io/kubernetes/pkg/controller"
 
+	logutil "github.com/oracle/oci-cloud-controller-manager/pkg/log"
 	"github.com/oracle/oci-cloud-controller-manager/pkg/oci/client"
 	"github.com/oracle/oci-cloud-controller-manager/pkg/oci/instancemeta"
 	"github.com/oracle/oci-cloud-controller-manager/pkg/oci/util"
@@ -61,6 +62,8 @@ type CloudProvider struct {
 
 	securityListManager securityListManager
 	config              *Config
+
+	logger *zap.SugaredLogger
 }
 
 // Compile time check that CloudProvider implements the cloudprovider.Interface
@@ -69,17 +72,21 @@ var _ cloudprovider.Interface = &CloudProvider{}
 
 // NewCloudProvider creates a new oci.CloudProvider.
 func NewCloudProvider(config *Config) (cloudprovider.Interface, error) {
-	cp, err := buildConfigurationProvider(config)
+	logger := logutil.Logger()
+	defer logger.Sync()
+	zap.ReplaceGlobals(logger)
+
+	cp, err := buildConfigurationProvider(logger, config)
 	if err != nil {
 		return nil, err
 	}
-	c, err := client.New(cp)
+	c, err := client.New(logger.Sugar(), cp)
 	if err != nil {
 		return nil, err
 	}
 
 	if config.CompartmentID == "" {
-		glog.Info("Compartment not supplied in config: attempting to infer from instance metadata")
+		logger.Info("Compartment not supplied in config: attempting to infer from instance metadata")
 		metadata, err := instancemeta.New().Get()
 		if err != nil {
 			return nil, err
@@ -88,7 +95,7 @@ func NewCloudProvider(config *Config) (cloudprovider.Interface, error) {
 	}
 
 	if !config.LoadBalancer.Disabled && config.VCNID == "" {
-		glog.Infof("No vcn provided in cloud provider config. Falling back to looking up VCN via LB subnet.")
+		logger.Info("No VCN provided in cloud provider config. Falling back to looking up VCN via LB subnet.")
 		subnet, err := c.Networking().GetSubnet(context.Background(), config.LoadBalancer.Subnet1)
 		if err != nil {
 			return nil, errors.Wrap(err, "get subnet for loadBalancer.subnet1")
@@ -99,6 +106,7 @@ func NewCloudProvider(config *Config) (cloudprovider.Interface, error) {
 	return &CloudProvider{
 		client: c,
 		config: config,
+		logger: logger.Sugar(),
 	}, nil
 }
 
@@ -130,7 +138,7 @@ func (cp *CloudProvider) Initialize(clientBuilder controller.ControllerClientBui
 
 	nodeInformer := factory.Core().V1().Nodes()
 	go nodeInformer.Informer().Run(wait.NeverStop)
-	glog.Info("Waiting for node informer cache to sync")
+	cp.logger.Info("Waiting for node informer cache to sync")
 	if !cache.WaitForCacheSync(wait.NeverStop, nodeInformer.Informer().HasSynced) {
 		utilruntime.HandleError(fmt.Errorf("Timed out waiting for node informer to sync"))
 	}
@@ -141,13 +149,13 @@ func (cp *CloudProvider) Initialize(clientBuilder controller.ControllerClientBui
 		if cp.config.LoadBalancer.SecurityListManagementMode != ManagementModeNone {
 			serviceInformer = factory.Core().V1().Services()
 			go serviceInformer.Informer().Run(wait.NeverStop)
-			glog.Info("Waiting for service informer cache to sync")
+			cp.logger.Info("Waiting for service informer cache to sync")
 			if !cache.WaitForCacheSync(wait.NeverStop, serviceInformer.Informer().HasSynced) {
 				utilruntime.HandleError(fmt.Errorf("Timed out waiting for service informer to sync"))
 			}
 		}
 
-		cp.securityListManager = newSecurityListManager(cp.client, serviceInformer, cp.config.LoadBalancer.SecurityLists, cp.config.LoadBalancer.SecurityListManagementMode)
+		cp.securityListManager = newSecurityListManager(cp.logger, cp.client, serviceInformer, cp.config.LoadBalancer.SecurityLists, cp.config.LoadBalancer.SecurityListManagementMode)
 	}
 }
 
@@ -159,21 +167,21 @@ func (cp *CloudProvider) ProviderName() string {
 // LoadBalancer returns a balancer interface. Also returns true if the interface
 // is supported, false otherwise.
 func (cp *CloudProvider) LoadBalancer() (cloudprovider.LoadBalancer, bool) {
-	glog.V(6).Info("Claiming to support Load Balancers")
+	cp.logger.Debug("Claiming to support Load Balancers")
 	return cp, !cp.config.LoadBalancer.Disabled
 }
 
 // Instances returns an instances interface. Also returns true if the interface
 // is supported, false otherwise.
 func (cp *CloudProvider) Instances() (cloudprovider.Instances, bool) {
-	glog.V(6).Info("Claiming to support instances")
+	cp.logger.Debug("Claiming to support instances")
 	return cp, true
 }
 
 // Zones returns a zones interface. Also returns true if the interface is
 // supported, false otherwise.
 func (cp *CloudProvider) Zones() (cloudprovider.Zones, bool) {
-	glog.V(6).Info("Claiming to support Zones")
+	cp.logger.Debug("Claiming to support Zones")
 	return cp, true
 }
 
@@ -200,16 +208,16 @@ func (cp *CloudProvider) HasClusterID() bool {
 	return true
 }
 
-func buildConfigurationProvider(config *Config) (common.ConfigurationProvider, error) {
+func buildConfigurationProvider(logger *zap.Logger, config *Config) (common.ConfigurationProvider, error) {
 	if config.Auth.UseInstancePrincipals {
-		glog.V(2).Info("Using instance principals configuration provider")
+		logger.Info("Using instance principals configuration provider")
 		cp, err := auth.InstancePrincipalConfigurationProvider()
 		if err != nil {
 			return nil, errors.Wrap(err, "InstancePrincipalConfigurationProvider")
 		}
 		return cp, nil
 	}
-	glog.V(2).Info("Using raw configuration provider")
+	logger.Info("Using raw configuration provider")
 	cp := common.NewRawConfigurationProvider(
 		config.Auth.TenancyID,
 		config.Auth.UserID,

pkg/oci/client/client.go

@@ -24,9 +24,9 @@ import (
 	"os"
 	"time"
 
+	"go.uber.org/zap"
 	"k8s.io/client-go/tools/cache"
 
-	"github.com/golang/glog"
 	"github.com/oracle/oci-go-sdk/common"
 	"github.com/oracle/oci-go-sdk/core"
 	"github.com/oracle/oci-go-sdk/loadbalancer"
@@ -46,16 +46,18 @@ type client struct {
 	loadbalancer *loadbalancer.LoadBalancerClient
 
 	subnetCache cache.Store
+	logger      *zap.SugaredLogger
 }
 
 // New constructs an OCI API client.
-func New(cp common.ConfigurationProvider) (Interface, error) {
+func New(logger *zap.SugaredLogger, cp common.ConfigurationProvider) (Interface, error) {
+	logger = logger.Named("ociClient")
 	compute, err := core.NewComputeClientWithConfigurationProvider(cp)
 	if err != nil {
 		return nil, errors.Wrap(err, "NewComputeClientWithConfigurationProvider")
 	}
 
-	err = configureCustomTransport(&compute.BaseClient)
+	err = configureCustomTransport(logger, &compute.BaseClient)
 	if err != nil {
 		return nil, errors.Wrap(err, "configuring load balancer client custom transport")
 	}
@@ -65,7 +67,7 @@ func New(cp common.ConfigurationProvider) (Interface, error) {
 		return nil, errors.Wrap(err, "NewVirtualNetworkClientWithConfigurationProvider")
 	}
 
-	err = configureCustomTransport(&network.BaseClient)
+	err = configureCustomTransport(logger, &network.BaseClient)
 	if err != nil {
 		return nil, errors.Wrap(err, "configuring load balancer client custom transport")
 	}
@@ -75,7 +77,7 @@ func New(cp common.ConfigurationProvider) (Interface, error) {
 		return nil, errors.Wrap(err, "NewLoadBalancerClientWithConfigurationProvider")
 	}
 
-	err = configureCustomTransport(&lb.BaseClient)
+	err = configureCustomTransport(logger, &lb.BaseClient)
 	if err != nil {
 		return nil, errors.Wrap(err, "configuring load balancer client custom transport")
 	}
@@ -86,6 +88,7 @@ func New(cp common.ConfigurationProvider) (Interface, error) {
 		loadbalancer: &lb,
 
 		subnetCache: cache.NewTTLStore(subnetCacheKeyFn, time.Duration(24)*time.Hour),
+		logger:      logger,
 	}
 
 	return c, nil
@@ -103,7 +106,7 @@ func (c *client) Compute() ComputeInterface {
 	return c
 }
 
-func configureCustomTransport(baseClient *common.BaseClient) error {
+func configureCustomTransport(logger *zap.SugaredLogger, baseClient *common.BaseClient) error {
 	httpClient := baseClient.HTTPClient.(*http.Client)
 
 	var transport *http.Transport
@@ -136,7 +139,7 @@ func configureCustomTransport(baseClient *common.BaseClient) error {
 
 	trustedCACertPath := os.Getenv("TRUSTED_CA_CERT_PATH")
 	if trustedCACertPath != "" {
-		glog.Infof("configuring OCI client with a new trusted ca: %s", trustedCACertPath)
+		logger.With("path", trustedCACertPath).Infof("Configuring OCI client with a new trusted ca")
 		trustedCACert, err := ioutil.ReadFile(trustedCACertPath)
 		if err != nil {
 			return errors.Wrapf(err, "failed to read root certificate: %s", trustedCACertPath)

pkg/oci/client/compute.go

@@ -18,7 +18,6 @@ import (
 	"context"
 	"strings"
 
-	"github.com/golang/glog"
 	"github.com/oracle/oci-go-sdk/core"
 	"github.com/pkg/errors"
 )
@@ -106,14 +105,19 @@ func (c *client) GetPrimaryVNICForInstance(ctx context.Context, compartmentID, i
 
 		for _, attachment := range resp.Items {
 			if attachment.LifecycleState != core.VnicAttachmentLifecycleStateAttached {
-				glog.Infof("VNIC attachment %q for instance %q has a state of %q (not %q)",
-					*attachment.Id, instanceID, attachment.LifecycleState, core.VnicAttachmentLifecycleStateAttached)
+				c.logger.With(
+					"instanceID", instanceID,
+					"vnicAttachmentID", *attachment.Id,
+					"expectedLifecycleState", core.VnicAttachmentLifecycleStateAttached,
+					"actualLifecycleState", attachment.LifecycleState,
+				).Info("VNIC attachment in unexpected lifecycle state")
 				continue
 			}
 
 			if attachment.VnicId == nil {
 				// Should never happen but lets be extra cautious as field is non-mandatory in OCI API.
-				glog.Errorf("VNIC attachment %q for instance %q is attached but has no VNIC ID", *attachment.Id, instanceID)
+				c.logger.With("instanceID", instanceID,
+					"vnicAttachmentID", *attachment.Id).Error("VNIC attachment is attached but has no VNIC ID")
 				continue
 			}
 
@@ -158,14 +162,19 @@ func (c *client) GetInstanceByNodeName(ctx context.Context, compartmentID, vcnID
 
 		for _, attachment := range resp.Items {
 			if attachment.LifecycleState != core.VnicAttachmentLifecycleStateAttached {
-				glog.Infof("VNIC attachment %q for instance %q has a life cycle state of %q (not %q)",
-					*attachment.Id, nodeName, attachment.LifecycleState, core.VnicAttachmentLifecycleStateAttached)
+				c.logger.With(
+					"nodeName", nodeName,
+					"vnicAttachmentID", *attachment.Id,
+					"expectedLifecycleState", core.VnicAttachmentLifecycleStateAttached,
+					"actualLifecycleState", attachment.LifecycleState,
+				).Info("VNIC attachment in unexpected lifecycle state")
 				continue
 			}
 
 			if attachment.VnicId == nil {
 				// Should never happen but lets be extra cautious as field is non-mandatory in OCI API.
-				glog.Errorf("VNIC attachment %q for instance %q is attached but has no VNIC ID", *attachment.Id, nodeName)
+				c.logger.With("nodeName", nodeName,
+					"vnicAttachmentID", *attachment.Id).Error("VNIC attachment is attached but has no VNIC ID")
 				continue
 			}
 
@@ -191,7 +200,8 @@ func (c *client) GetInstanceByNodeName(ctx context.Context, compartmentID, vcnID
 				}
 
 				if IsInstanceInTerminalState(instance) {
-					glog.Warningf("Instance %q is in state %q which is a terminal state", instance.Id, instance.LifecycleState)
+					c.logger.With("instanceID", *instance.Id,
+						"lifecycleState", instance.LifecycleState).Warn("Instance in a terminal state")
 					continue
 				}