Merge pull request #375 from crawford/logging

 *: improve logging messages

Author: openshift-merge-robot

cmd/openshift-install/main.go

@@ -4,7 +4,7 @@ import (
 	"fmt"
 	"os"
 
-	log "github.com/sirupsen/logrus"
+	"github.com/sirupsen/logrus"
 	"gopkg.in/alecthomas/kingpin.v2"
 
 	"github.com/openshift/installer/pkg/asset"
@@ -23,19 +23,24 @@ var (
 	destroyCommand = kingpin.Command("destroy-cluster", "Destroy an OpenShift cluster")
 
 	dirFlag  = kingpin.Flag("dir", "assets directory").Default(".").String()
-	logLevel = kingpin.Flag("log-level", "log level (e.g. \"debug\")").Default("warn").Enum("debug", "info", "warn", "error", "fatal", "panic")
+	logLevel = kingpin.Flag("log-level", "log level (e.g. \"debug\")").Default("info").Enum("debug", "info", "warn", "error")
 
 	version = "was not built correctly" // set in hack/build.sh
 )
 
 func main() {
 	command := kingpin.Parse()
-	l, err := log.ParseLevel(*logLevel)
-	if err != nil {
+
+	logrus.SetFormatter(&logrus.TextFormatter{
+		DisableTimestamp:       true,
+		DisableLevelTruncation: true,
+	})
+	if level, err := logrus.ParseLevel(*logLevel); err == nil {
+		logrus.SetLevel(level)
+	} else {
 		// By definition we should never enter this condition since kingpin should be guarding against incorrect values.
-		log.Fatalf("invalid log-level: %v", err)
+		logrus.Panicf("Invalid log-level: %v", err)
 	}
-	log.SetLevel(l)
 
 	if command == versionCommand.FullCommand() {
 		fmt.Printf("%s %s\n", os.Args[0], version)
@@ -77,26 +82,20 @@ func main() {
 		for _, asset := range targetAssets {
 			st, err := assetStore.Fetch(asset)
 			if err != nil {
-				log.Fatalf("failed to generate asset: %v", err)
-				os.Exit(1)
+				logrus.Fatalf("Failed to generate asset: %v", err)
 			}
 
 			if err := st.PersistToFile(*dirFlag); err != nil {
-				log.Fatalf("failed to write target to disk: %v", err)
-				os.Exit(1)
+				logrus.Fatalf("Failed to write asset (%s) to disk: %v", asset.Name(), err)
 			}
 		}
 	case destroyCommand.FullCommand():
-		destroyer, err := destroy.New(l, *dirFlag)
+		destroyer, err := destroy.New(logrus.StandardLogger(), *dirFlag)
 		if err != nil {
-			log.Fatalf("failed to create destroyer: %v", err)
-			os.Exit(1)
+			logrus.Fatalf("Failed while preparing to destroy cluster: %v", err)
 		}
 		if err := destroyer.Run(); err != nil {
-			log.Fatalf("destroy failed: %v", err)
-			os.Exit(1)
+			logrus.Fatalf("Failed to destroy cluster: %v", err)
 		}
-
 	}
-
 }

glide.lock

@@ -5,7 +5,7 @@ import:
 - package: github.com/ghodss/yaml
   version: 73d445a93680fa1a78ae23a5839bad48f32ba1ee
 - package: github.com/sirupsen/logrus
-  version: 081307d9bc1364753142d5962fc1d795c742baaf
+  version: 1.1.0
 - package: gopkg.in/yaml.v2
   version: 53feefa2559fb8dfa8d81baad31be332c97d6c77
 - package: gopkg.in/alecthomas/kingpin.v2

glide.yaml

@@ -7,7 +7,7 @@ import (
 	"os"
 	"path/filepath"
 
-	log "github.com/sirupsen/logrus"
+	"github.com/sirupsen/logrus"
 
 	"github.com/openshift/installer/data"
 	"github.com/openshift/installer/pkg/asset"
@@ -73,6 +73,8 @@ func (c *Cluster) Generate(parents map[asset.Asset]*asset.State) (*asset.State,
 		return nil, err
 	}
 
+	logrus.Infof("Using Terraform to create cluster...")
+
 	// This runs the terraform in a temp directory, the tfstate file will be returned
 	// to the asset store to persist it on the disk.
 	if err := terraform.Init(tmpDir); err != nil {
@@ -81,22 +83,24 @@ func (c *Cluster) Generate(parents map[asset.Asset]*asset.State) (*asset.State,
 
 	stateFile, err := terraform.Apply(tmpDir)
 	if err != nil {
-		// we should try to fetch the terraform state file.
-		log.Errorf("terraform failed: %v", err)
+		err = fmt.Errorf("terraform failed: %v", err)
 	}
 
-	data, err := ioutil.ReadFile(stateFile)
-	if err != nil {
-		return nil, fmt.Errorf("failed to read tfstate file %q: %v", stateFile, err)
+	data, err2 := ioutil.ReadFile(stateFile)
+	if err2 != nil {
+		if err == nil {
+			err = err2
+		} else {
+			logrus.Errorf("Failed to read tfstate (%q): %v", stateFile, err2)
+		}
 	}
 
-	// TODO(yifan): Use the kubeconfig to verify the cluster is up.
 	return &asset.State{
 		Contents: []asset.Content{
 			{
 				Name: stateFileName,
 				Data: data,
 			},
 		},
-	}, nil
+	}, err
 }

pkg/asset/cluster/cluster.go

@@ -25,7 +25,7 @@ func (s *StoreImpl) Fetch(asset Asset) (*State, error) {
 }
 
 func (s *StoreImpl) fetch(asset Asset, indent string) (*State, error) {
-	logrus.Infof("%sFetching %s...", indent, asset.Name())
+	logrus.Debugf("%sFetching %s...", indent, asset.Name())
 	state, ok := s.assets[asset]
 	if ok {
 		logrus.Debugf("%sFound %s...", indent, asset.Name())

pkg/asset/store.go

@@ -1,27 +1,18 @@
 package destroy
 
 import (
-	"os"
-
 	atd "github.com/openshift/hive/contrib/pkg/awstagdeprovision"
 	"github.com/openshift/installer/pkg/types"
-	log "github.com/sirupsen/logrus"
+	"github.com/sirupsen/logrus"
 )
 
 // NewAWS returns an AWS destroyer from ClusterMetadata.
-func NewAWS(level log.Level, metadata *types.ClusterMetadata) (Destroyer, error) {
+func NewAWS(logger logrus.FieldLogger, metadata *types.ClusterMetadata) (Destroyer, error) {
 	return &atd.ClusterUninstaller{
 		Filters:     metadata.ClusterPlatformMetadata.AWS.Identifier,
 		Region:      metadata.ClusterPlatformMetadata.AWS.Region,
 		ClusterName: metadata.ClusterName,
-		Logger: log.NewEntry(&log.Logger{
-			Out: os.Stdout,
-			Formatter: &log.TextFormatter{
-				FullTimestamp: true,
-			},
-			Hooks: make(log.LevelHooks),
-			Level: level,
-		}),
+		Logger:      logger,
 	}, nil
 }
 

pkg/destroy/aws.go

@@ -6,7 +6,7 @@ import (
 	"io/ioutil"
 	"path/filepath"
 
-	log "github.com/sirupsen/logrus"
+	"github.com/sirupsen/logrus"
 
 	"github.com/openshift/installer/pkg/asset/metadata"
 	"github.com/openshift/installer/pkg/types"
@@ -19,13 +19,13 @@ type Destroyer interface {
 }
 
 // NewFunc is an interface for creating platform-specific destroyers.
-type NewFunc func(level log.Level, metadata *types.ClusterMetadata) (Destroyer, error)
+type NewFunc func(logger logrus.FieldLogger, metadata *types.ClusterMetadata) (Destroyer, error)
 
 // Registry maps ClusterMetadata.Platform() to per-platform Destroyer creators.
 var Registry = make(map[string]NewFunc)
 
 // New returns a Destroyer based on `metadata.json` in `rootDir`.
-func New(level log.Level, rootDir string) (Destroyer, error) {
+func New(logger logrus.FieldLogger, rootDir string) (Destroyer, error) {
 	path := filepath.Join(rootDir, metadata.MetadataFilename)
 	raw, err := ioutil.ReadFile(filepath.Join(rootDir, metadata.MetadataFilename))
 	if err != nil {
@@ -46,5 +46,5 @@ func New(level log.Level, rootDir string) (Destroyer, error) {
 	if !ok {
 		return nil, fmt.Errorf("no destroyers registered for %q", platform)
 	}
-	return creator(level, cmetadata)
+	return creator(logger, cmetadata)
 }

pkg/destroy/destroyer.go

@@ -10,7 +10,7 @@ import (
 	libvirt "github.com/libvirt/libvirt-go"
 	"github.com/openshift/installer/pkg/destroy"
 	"github.com/openshift/installer/pkg/types"
-	log "github.com/sirupsen/logrus"
+	"github.com/sirupsen/logrus"
 	"k8s.io/apimachinery/pkg/util/wait"
 )
 
@@ -44,13 +44,13 @@ var AlwaysTrueFilter = func() filterFunc {
 // deleteFunc type is the interface a function needs to implement to be called as a goroutine.
 // The (bool, error) return type mimics wait.ExponentialBackoff where the bool indicates successful
 // completion, and the error is for unrecoverable errors.
-type deleteFunc func(conn *libvirt.Connect, filter filterFunc, logger log.FieldLogger) (bool, error)
+type deleteFunc func(conn *libvirt.Connect, filter filterFunc, logger logrus.FieldLogger) (bool, error)
 
 // ClusterUninstaller holds the various options for the cluster we want to delete.
 type ClusterUninstaller struct {
 	LibvirtURI string
 	Filter     filterFunc
-	Logger     log.FieldLogger
+	Logger     logrus.FieldLogger
 }
 
 // Run is the entrypoint to start the uninstall process
@@ -80,7 +80,7 @@ func (o *ClusterUninstaller) Run() error {
 	return nil
 }
 
-func deleteRunner(deleteFuncName string, dFunction deleteFunc, conn *libvirt.Connect, filter filterFunc, logger log.FieldLogger, channel chan string) {
+func deleteRunner(deleteFuncName string, dFunction deleteFunc, conn *libvirt.Connect, filter filterFunc, logger logrus.FieldLogger, channel chan string) {
 	backoffSettings := wait.Backoff{
 		Duration: time.Second * 10,
 		Factor:   1.3,
@@ -108,7 +108,7 @@ func populateDeleteFuncs(funcs map[string]deleteFunc) {
 	funcs["deleteNetwork"] = deleteNetwork
 }
 
-func deleteDomains(conn *libvirt.Connect, filter filterFunc, logger log.FieldLogger) (bool, error) {
+func deleteDomains(conn *libvirt.Connect, filter filterFunc, logger logrus.FieldLogger) (bool, error) {
 	logger.Debug("Deleting libvirt domains")
 	defer logger.Debugf("Exiting deleting libvirt domains")
 
@@ -143,7 +143,7 @@ func deleteDomains(conn *libvirt.Connect, filter filterFunc, logger log.FieldLog
 	return true, nil
 }
 
-func deleteVolumes(conn *libvirt.Connect, filter filterFunc, logger log.FieldLogger) (bool, error) {
+func deleteVolumes(conn *libvirt.Connect, filter filterFunc, logger logrus.FieldLogger) (bool, error) {
 	logger.Debug("Deleting libvirt volumes")
 	defer logger.Debugf("Exiting deleting libvirt volumes")
 
@@ -209,7 +209,7 @@ func deleteVolumes(conn *libvirt.Connect, filter filterFunc, logger log.FieldLog
 	return true, nil
 }
 
-func deleteNetwork(conn *libvirt.Connect, filter filterFunc, logger log.FieldLogger) (bool, error) {
+func deleteNetwork(conn *libvirt.Connect, filter filterFunc, logger logrus.FieldLogger) (bool, error) {
 	logger.Debug("Deleting libvirt network")
 	defer logger.Debugf("Exiting deleting libvirt network")
 
@@ -245,17 +245,10 @@ func deleteNetwork(conn *libvirt.Connect, filter filterFunc, logger log.FieldLog
 }
 
 // New returns libvirt Uninstaller from ClusterMetadata.
-func New(level log.Level, metadata *types.ClusterMetadata) (destroy.Destroyer, error) {
+func New(logger logrus.FieldLogger, metadata *types.ClusterMetadata) (destroy.Destroyer, error) {
 	return &ClusterUninstaller{
 		LibvirtURI: metadata.ClusterPlatformMetadata.Libvirt.URI,
 		Filter:     AlwaysTrueFilter(), //TODO: change to ClusterNamePrefixFilter when all resources are prefixed.
-		Logger: log.NewEntry(&log.Logger{
-			Out: os.Stdout,
-			Formatter: &log.TextFormatter{
-				FullTimestamp: true,
-			},
-			Hooks: make(log.LevelHooks),
-			Level: level,
-		}),
+		Logger:     logger,
 	}, nil
 }