Migrate to zap logger #164

harveylowndes · 2018-08-17T08:35:38Z

Migrates logging from to go.uber.org/zap from github.com/golang/glog and adds the following flags:

--log-level=debug  # control log level
--log-json  # output log as json
--logfile-path  # if provided reload

prydie

I haven't gone through FSS in detail but the same kind of changes apply 🙂

prydie · 2018-08-29T14:51:44Z

pkg/oci/client/client.go

-func FromConfig(cfg *Config) (ProvisionerClient, error) {
-	config, err := newConfigurationProvider(cfg)
+func FromConfig(logger *zap.SugaredLogger, cfg *Config) (ProvisionerClient, error) {
+


prydie · 2018-08-31T12:34:44Z

cmd/main.go

@@ -69,25 +80,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.Fatalf("Failed to load config: %v", err)


logger.With(zap.Error(err)).Fatal("Failed to load config")

prydie · 2018-08-31T12:35:09Z

cmd/main.go

 	}

 	clientset, err := kubernetes.NewForConfig(config)
 	if err != nil {
-		glog.Fatalf("Failed to create client: %v", err)
+		logger.Fatalf("Failed to create client: %v", err)


logger.With(zap.Error(err)).Fatal("Failed to create Kubernetes client")

prydie · 2018-08-31T12:35:36Z

cmd/main.go

 	}

 	// 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.Fatalf("Error getting server version: %v", err)


logger.With(zap.Error(err)).Fatal("Failed to get kube-apiserver version")

prydie · 2018-08-31T12:36:26Z

cmd/main.go

@@ -96,21 +107,22 @@ func main() {
 		provisionerType = core.ProvisionerNameBlock
 	}

-	glog.Infof("Starting volume provisioner in %s mode", provisionerType)
+	logger.With("provisionerType", provisionerType).Info("Starting volume provisioner in %s mode", provisionerType)


logger = logger.With("provisionerType", provisionerType) logger.Info("Starting volume provisioner in %q mode", provisionerType)

prydie · 2018-08-31T12:44:27Z

pkg/provisioner/block/block.go


 	if volumeRoundingEnabled(options.Parameters) {
 		if block.volumeRoundingEnabled && block.minVolumeSize.Cmp(capacity) == 1 {
-			glog.Warningf("PVC requested storage less than %s. Rounding up to ensure volume creation", block.minVolumeSize.String())
+			block.logger.Warnf("PVC requested storage less than %s. Rounding up to ensure volume creation.", block.minVolumeSize.String())


logger.Warn("Attempted to provision volume with a capacity less than the minimum. Rounding up to ensure volume creation.")

prydie · 2018-08-31T12:50:49Z

pkg/provisioner/block/block.go


 			volSizeMB = int(roundUpSize(block.minVolumeSize.Value(), 1024*1024))
 			capacity = block.minVolumeSize
 		}
 	}

-	glog.Infof("Creating volume size=%v AD=%s compartmentOCID=%q", volSizeMB, *ad.Name, block.client.CompartmentOCID())
+	block.logger.With("volumeSize", volSizeMB).With("name", *ad.Name).With("compartmentOCID", block.client.CompartmentOCID()).Info("Creating volume.")


Not needed (see log in comment above with all this)

prydie · 2018-08-31T12:52:20Z

pkg/provisioner/block/block.go

@@ -171,7 +174,7 @@ func (block *blockProvisioner) Provision(options controller.VolumeOptions, ad *i
 	}

 	if value, ok := options.PVC.Annotations[ociVolumeBackupID]; ok {
-		glog.Infof("Creating volume from backup ID %s", value)
+		block.logger.With("volumeBackupOCID", value).Info("Creating volume from backup.")


s/block.logger/logger/

prydie · 2018-08-31T12:53:06Z

pkg/provisioner/core/provisioner.go

 	configPath, ok := os.LookupEnv("CONFIG_YAML_FILENAME")
 	if !ok {
 		configPath = configFilePath
 	}

 	f, err := os.Open(configPath)
 	if err != nil {
-		glog.Fatalf("Unable to load volume provisioner configuration file: %v", configPath)
+		logger.With("configPath", configPath).Fatal("Unable to load volume provisioner configuration file.")


logger.With(zap.Error(err), "configPath", configPath).Fatal("Unable to load volume provisioner configuration file.")

prydie · 2018-08-31T12:54:45Z

pkg/provisioner/core/utils.go

@@ -80,7 +79,7 @@ func (p *OCIProvisioner) chooseAvailabilityDomain(ctx context.Context, pvc *v1.P
 			return "", nil, fmt.Errorf("failed to choose availability domain; no zone labels (%q) on nodes", metav1.LabelZoneFailureDomain)
 		}
 		availabilityDomainName = util.ChooseZoneForVolume(validADs, pvc.Name)
-		glog.Infof("Zone not specified so %s selected", availabilityDomainName)
+		p.logger.With("zone", availabilityDomainName).Info("Zone not specified, selected alternative zone.")


p.logger.With("availabilityDomain", availabilityDomainName).Info("No availability domain provided. Selecting one automatically.")

prydie

Now we're getting into the real nitty-gritty 🙂

prydie · 2018-09-03T15:44:56Z

pkg/provisioner/block/block.go


 	if volumeRoundingEnabled(options.Parameters) {
 		if block.volumeRoundingEnabled && block.minVolumeSize.Cmp(capacity) == 1 {
-			glog.Warningf("PVC requested storage less than %s. Rounding up to ensure volume creation", block.minVolumeSize.String())
-
+			logger.Warn("Attempted to provision volume with a capacity less than the minimum. Rounding up to ensure volume creation.")


Should probably move this log down a line and then add a .With("roundedVolumeSize", volSizeMB)

prydie · 2018-09-03T15:47:34Z

pkg/provisioner/block/block.go

-	glog.Infof("Volume size: %dMB", volSizeMB)
+
+	logger := block.logger.With(
+		"compartmentID", block.client.CompartmentOCID(),


On reflection adding the "compartmentID" and "tenancyID" fields should be moved to the constructor (NewBlockProvisioner) so that they're applied in both the Provision() and Delete() methods.

prydie · 2018-09-03T15:49:29Z

pkg/provisioner/fss/fss.go

 	return &filesystemProvisioner{
 		client: client,
+		logger: logger,


Add the "compartmentID" and "tenancyID" fields here (same as suggested above in NewBlockProvisioner())

prydie · 2018-09-03T15:52:01Z

pkg/provisioner/fss/fss_test.go

@@ -19,6 +19,7 @@ import (
 	"reflect"
 	"testing"

+	"go.uber.org/zap"


Import grouping

prydie · 2018-09-03T15:54:20Z

pkg/provisioner/fss/fss.go

 	ctx, cancel := context.WithTimeout(ctx, fsp.client.Timeout())
 	defer cancel()
 	if _, err := fsp.client.FSS().DeleteExport(ctx, filestorage.DeleteExportRequest{
 		ExportId: &exportID,
 	}); err != nil {
 		if !provisioner.IsNotFound(err) {
-			glog.Errorf("Failed to delete export exportID=%q: %v", exportID, err)
+			logger.With(zap.Error(err), "exportOCID", exportID).Error("Failed to delete export.")


remove exportID field (will be assigned above).

prydie · 2018-09-03T16:30:40Z

pkg/provisioner/block/block.go

@@ -171,7 +178,7 @@ func (block *blockProvisioner) Provision(options controller.VolumeOptions, ad *i
 	}

 	if value, ok := options.PVC.Annotations[ociVolumeBackupID]; ok {
-		glog.Infof("Creating volume from backup ID %s", value)
+		logger.With("volumeBackupOCID", value).Info("Creating volume from backup.")
 		volumeDetails.SourceDetails = &core.VolumeSourceFromVolumeBackupDetails{Id: &value}
 	}



Below log that we're waitForVolumeAvailable() .With("volumeID", *newVolume.Id)

prydie · 2018-09-03T16:34:31Z

pkg/provisioner/block/block_test.go

@@ -146,6 +154,9 @@ func TestCreateVolumeFailure(t *testing.T) {
 }

 func TestVolumeRoundingLogic(t *testing.T) {
+
+	logger := zap.S()


Don't bother assigning; just pass zap.S() directly.

prydie · 2018-09-03T16:34:35Z

pkg/provisioner/block/block_test.go

@@ -100,6 +105,9 @@ func TestCreateVolumeFromBackup(t *testing.T) {
 }

 func TestCreateVolumeFailure(t *testing.T) {
+
+	logger := zap.S()


Don't bother assigning; just pass zap.S() directly.

prydie · 2018-09-03T16:34:44Z

pkg/provisioner/block/block_test.go

@@ -61,6 +63,9 @@ func TestResolveFSTypeWhenConfigured(t *testing.T) {

 func TestCreateVolumeFromBackup(t *testing.T) {
 	// test creating a volume from an existing backup
+
+	logger := zap.S()


Don't bother assigning; just pass zap.S() directly.

prydie · 2018-09-03T16:35:01Z

pkg/provisioner/core/provisioner.go

@@ -20,7 +20,8 @@ import (
 	"strings"
 	"time"

-	"github.com/golang/glog"
+	"go.uber.org/zap"


import grouping

prydie

A few more

prydie · 2018-09-04T10:39:05Z

pkg/provisioner/fss/fss.go

 	return &filesystemProvisioner{
 		client: client,
+		logger: logger.With(
+			"compartmentID", client.CompartmentOCID,


Shouldn't you be calling these as they're methods?

prydie · 2018-09-04T10:41:11Z

pkg/provisioner/fss/fss.go

 	// Create the FileSystem.
 	var fsID string
 	{
 		ctx, cancel := context.WithTimeout(ctx, fsp.client.Timeout())
 		defer cancel()
+		logger.Info("Creating FileSystem")


Log above outside of this block.

prydie · 2018-09-04T10:43:15Z

pkg/provisioner/fss/fss.go

@@ -195,13 +206,13 @@ func (fsp *filesystemProvisioner) Provision(options controller.VolumeOptions, ad
 			PrivateIpId: &id,
 		})
 		if err != nil {
-			glog.Errorf("Failed to retrieve IP address for mount target privateIpID=%q: %v", id, err)
+			logger.Errorf("Failed to retrieve IP address for mount target privateIpID=%q: %v", id, err)


.With(zap.Error(err), "privateIPID", id)

prydie · 2018-09-04T10:49:10Z

pkg/provisioner/fss/fss.go

-	glog.Infof("Deleting export for filesystemID %v", filesystemID)
+	logger := fsp.logger.With(
+		"fileSystemOCID", filesystemID,
+		"volumeOCID", volume,


prydie · 2018-09-04T11:10:37Z

pkg/provisioner/fss/fss.go

 			return nil, err
 		}
 		serverIP = *getPrivateIPResponse.PrivateIp.IpAddress
 	}

-	glog.Infof("Creating persistent volume on mount target with private IP address %s", serverIP)
+	logger.With("privateIP", serverIP).Info("Creating persistent volume on mount target with private IP address.")


Maybe reword message to something along the lines of "Chose Mount Target Private IP"?

prydie · 2018-09-04T11:15:51Z

pkg/provisioner/fss/fss.go

 			},
 		})
 		if err != nil {
-			glog.Errorf("Failed to create a file system options=%#v: %v", options, err)
 			return nil, err
 		}
 		fsID = *resp.FileSystem.Id
 	}



reassign logger .With("fileSystemID", fsID)

prydie · 2018-09-04T11:16:40Z

pkg/provisioner/fss/fss.go

@@ -174,15 +185,15 @@ func (fsp *filesystemProvisioner) Provision(options controller.VolumeOptions, ad
 			},
 		})
 		if err != nil {
-			glog.Errorf("Failed to create export: %v", err)
+			logger.With(zap.Error(err)).Error("Failed to create export.")
 			return nil, err
 		}
 		exportSetID = *resp.Export.Id
 	}



reassign logger .With("exportSetID", exportSetID)

prydie · 2018-09-04T11:20:13Z

pkg/provisioner/fss/fss.go

 			return nil, err
 		}
 		exportSetID = *resp.Export.Id
 	}

 	if len(target.PrivateIpIds) == 0 {
-		glog.Errorf("Failed to find server IDs associated with the Mount Target (OCID %s) to provision a persistent volume", target.Id)
-		return nil, errors.Errorf("failed to find server IDs associated with the Mount Target with OCID %q", target.Id)
+		logger.With("targetID", *target.Id).Error("Failed to find server IDs associated with the Mount Target to provision a persistent volume")


Maybe change the error and log message to something along the lines of "Could not find any Private IPs for Mount Target"?

prydie

Couple final changes and needs rebasing but looking good 👍

prydie · 2018-09-17T13:15:26Z

cmd/main.go

+
+	//logger.Infof("logtostderr is set to %b", flag.Lookup("logtostderr").Value.(flag.Getter).Get().(bool))
+
+	//logger.Sugar().With("version", version, "build", build).Info("oci-volume-provisioner")


We should log the version and build.

prydie · 2018-09-17T13:15:33Z

cmd/main.go

+
+	logger := log.Sugar()
+
+	//logger.Infof("logtostderr is set to %b", flag.Lookup("logtostderr").Value.(flag.Getter).Get().(bool))


This can be removed.

prydie · 2018-09-17T13:16:49Z

cmd/main.go

 	"github.com/oracle/oci-volume-provisioner/pkg/provisioner/core"
 	"github.com/oracle/oci-volume-provisioner/pkg/signals"
+	"go.uber.org/zap"


Import grouping

prydie · 2018-09-17T13:19:15Z

cmd/main.go

 	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")


We don't need this now (it's glog specific).

prydie · 2018-09-17T13:20:55Z

pkg/oci/client/client.go

-	"github.com/golang/glog"
+	"github.com/pkg/errors"
+	"go.uber.org/zap"
+


Confusingly github.com/oracle/oci-go-sdk is actually an 3rd partly lib rather than internal and as such should be grouped with zap and errors etc.

prydie · 2018-09-17T13:23:50Z

pkg/oci/client/client.go

@@ -111,24 +114,30 @@ func (p *provisionerClient) Timeout() time.Duration {
 func (p *provisionerClient) CompartmentOCID() (compartmentOCID string) {


func (p *provisionerClient) CompartmentOCID() string { if p.cfg.CompartmentOCID == "" { if p.metadata == nil { p.logger.Fatal("Unable to get compartment OCID. Please provide this via config.") return } p.logger.With("compartmentOCID", p.metadata.CompartmentOCID).Infof("'CompartmentID' not given. Using compartment OCID from instance metadata.") p.cfg.CompartmentOCID = p.metadata.CompartmentOCID } return p.cfg.CompartmentOCID }

prydie · 2018-09-17T13:25:35Z

pkg/oci/client/client.go

 	} else {
 		compartmentOCID = p.cfg.CompartmentOCID
 	}
 	return
 }

-func (p *provisionerClient) TenancyOCID() string {
-	return p.cfg.Auth.TenancyOCID
+func (p *provisionerClient) TenancyOCID() (tenancyOCID string) {


No need to name the return type here

prydie · 2018-09-17T13:46:24Z

pkg/oci/client/client.go

 	blockStorage   *core.BlockstorageClient
 	identity       *identity.IdentityClient
 	fileStorage    *filestorage.FileStorageClient
 	virtualNetwork *core.VirtualNetworkClient
+	context        context.Context


Contexts should never be added as a property on a struct.

owainlewis · 2018-09-26T11:24:52Z

Awaiting fix for system-tests

owainlewis added the enhancement label Aug 17, 2018

harveylowndes force-pushed the migrate-logs-to-zap branch 5 times, most recently from 8a007d2 to 8d81a23 Compare August 17, 2018 14:48

harveylowndes force-pushed the migrate-logs-to-zap branch 2 times, most recently from 8ce6d07 to 7da5bfb Compare August 29, 2018 10:43

harveylowndes requested a review from prydie August 31, 2018 08:15

prydie suggested changes Aug 31, 2018

View reviewed changes

harveylowndes force-pushed the migrate-logs-to-zap branch 2 times, most recently from daedd0c to 96f725d Compare September 3, 2018 15:19

prydie suggested changes Sep 3, 2018

View reviewed changes

harveylowndes force-pushed the migrate-logs-to-zap branch 2 times, most recently from fde08e3 to 543a114 Compare September 4, 2018 10:34

harveylowndes changed the title ~~WIP: Migrate to zap logger~~ Migrate to zap logger Sep 4, 2018

prydie suggested changes Sep 5, 2018

View reviewed changes

harveylowndes force-pushed the migrate-logs-to-zap branch 3 times, most recently from aae1dc4 to affa9cf Compare September 5, 2018 16:30

prydie suggested changes Sep 17, 2018

View reviewed changes

harveylowndes force-pushed the migrate-logs-to-zap branch 3 times, most recently from c5696fa to 76e4ba4 Compare September 24, 2018 15:38

Harvey Lowndes added 6 commits September 25, 2018 09:38

Migrate logs to zap

a060c61

Update Dependencies

f5c5dc4

Fix errors

f0a13a5

Fix errors

4757cb6

Add fixed version to nginx

f55dace

Review changes

844bbf5

harveylowndes force-pushed the migrate-logs-to-zap branch from 76e4ba4 to 45750ca Compare September 25, 2018 08:40

More review changes

0dbb763

harveylowndes force-pushed the migrate-logs-to-zap branch from 45750ca to 0dbb763 Compare September 26, 2018 13:22

Revert GOOS to linux

5d5cb08

prydie approved these changes Sep 27, 2018

View reviewed changes

prydie merged commit 4e4fed8 into master Sep 27, 2018

prydie deleted the migrate-logs-to-zap branch September 27, 2018 11:49


		//logger.Infof("logtostderr is set to %b", flag.Lookup("logtostderr").Value.(flag.Getter).Get().(bool))

		//logger.Sugar().With("version", version, "build", build).Info("oci-volume-provisioner")


		logger := log.Sugar()

		//logger.Infof("logtostderr is set to %b", flag.Lookup("logtostderr").Value.(flag.Getter).Get().(bool))

		@@ -111,24 +114,30 @@ func (p *provisionerClient) Timeout() time.Duration {
		func (p *provisionerClient) CompartmentOCID() (compartmentOCID string) {

Migrate to zap logger #164

Migrate to zap logger #164

Conversation

harveylowndes commented Aug 17, 2018 • edited Loading

prydie left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

prydie left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

prydie left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

prydie left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

owainlewis commented Sep 26, 2018

harveylowndes commented Aug 17, 2018 •

edited

Loading