Merge branch 'master' into support-multi-az-pvs

Signed-off-by: Ashish Amarnath <ashish.amarnath@gmail.com>

Gopkg.lock

@@ -223,6 +223,12 @@
   packages = ["."]
   revision = "d0303fe809921458f417bcf828397a65db30a7e4"
 
+[[projects]]
+  name = "github.com/pkg/errors"
+  packages = ["."]
+  revision = "645ef00459ed84a119197bfb8d8205042c6df63d"
+  version = "v0.8.0"
+
 [[projects]]
   name = "github.com/pmezard/go-difflib"
   packages = ["difflib"]
@@ -257,6 +263,12 @@
   packages = ["."]
   revision = "541ff5ee47f1dddf6a5281af78307d921524bcb5"
 
+[[projects]]
+  name = "github.com/sirupsen/logrus"
+  packages = [".","hooks/test"]
+  revision = "f006c2ac4710855cf0f916dd6b77acf6b048dc6e"
+  version = "v1.0.3"
+
 [[projects]]
   branch = "master"
   name = "github.com/spf13/afero"
@@ -391,6 +403,6 @@
 [solve-meta]
   analyzer-name = "dep"
   analyzer-version = 1
-  inputs-digest = "1739acba4589d0e177479f7cad479483b6951d15483af6b8c72028a8ec4b275e"
+  inputs-digest = "3585b76a035a388e1521b936d43a60ef22024b9508c48a089334c6693eaaf559"
   solver-name = "gps-cdcl"
   solver-version = 1

pkg/backup/backup.go

@@ -25,6 +25,8 @@ import (
 	"strings"
 	"time"
 
+	"github.com/pkg/errors"
+
 	"k8s.io/apimachinery/pkg/api/meta"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"k8s.io/apimachinery/pkg/runtime"
@@ -112,13 +114,14 @@ func (ctx *backupContext) getResourceIncludesExcludes(helper discovery.Helper, i
 	return collections.GenerateIncludesExcludes(
 		includes,
 		excludes,
-		func(item string) (string, error) {
+		func(item string) string {
 			gr, err := helper.ResolveGroupResource(item)
 			if err != nil {
-				return "", err
+				ctx.log("Unable to resolve resource %q: %v", item, err)
+				return ""
 			}
 
-			return gr.String(), nil
+			return gr.String()
 		},
 	)
 }
@@ -238,7 +241,7 @@ func (kb *kubernetesBackupper) backupResource(
 
 	gv, err := schema.ParseGroupVersion(group.GroupVersion)
 	if err != nil {
-		return err
+		return errors.Wrapf(err, "error parsing GroupVersion %s", group.GroupVersion)
 	}
 	gvr := schema.GroupVersionResource{Group: gv.Group, Version: gv.Version}
 	gr := schema.GroupResource{Group: gv.Group, Resource: resource.Name}
@@ -297,13 +300,13 @@ func (kb *kubernetesBackupper) backupResource(
 		}
 		unstructuredList, err := resourceClient.List(metav1.ListOptions{LabelSelector: labelSelector})
 		if err != nil {
-			return err
+			return errors.WithStack(err)
 		}
 
 		// do the backup
 		items, err := meta.ExtractList(unstructuredList)
 		if err != nil {
-			return err
+			return errors.WithStack(err)
 		}
 
 		action := kb.actions[gr]
@@ -311,7 +314,7 @@ func (kb *kubernetesBackupper) backupResource(
 		for _, item := range items {
 			unstructured, ok := item.(runtime.Unstructured)
 			if !ok {
-				errs = append(errs, fmt.Errorf("unexpected type %T", item))
+				errs = append(errs, errors.Errorf("unexpected type %T", item))
 				continue
 			}
 
@@ -399,7 +402,7 @@ func (*realItemBackupper) backupItem(ctx *backupContext, item map[string]interfa
 
 	itemBytes, err := json.Marshal(item)
 	if err != nil {
-		return err
+		return errors.WithStack(err)
 	}
 
 	hdr := &tar.Header{
@@ -411,11 +414,11 @@ func (*realItemBackupper) backupItem(ctx *backupContext, item map[string]interfa
 	}
 
 	if err := ctx.w.WriteHeader(hdr); err != nil {
-		return err
+		return errors.WithStack(err)
 	}
 
 	if _, err := ctx.w.Write(itemBytes); err != nil {
-		return err
+		return errors.WithStack(err)
 	}
 
 	return nil

pkg/backup/volume_snapshot_action.go

@@ -17,9 +17,10 @@ limitations under the License.
 package backup
 
 import (
-	"errors"
 	"fmt"
 
+	"github.com/pkg/errors"
+
 	"k8s.io/apimachinery/pkg/util/clock"
 
 	api "github.com/heptio/ark/pkg/apis/ark/v1"
@@ -75,7 +76,7 @@ func (a *volumeSnapshotAction) Execute(ctx ActionContext, volume map[string]inte
 	volumeID, err := kubeutil.GetVolumeID(volume)
 	// non-nil error means it's a supported PV source but volume ID can't be found
 	if err != nil {
-		return fmt.Errorf("error getting volume ID for backup %q, PersistentVolume %q: %v", backupName, name, err)
+		return errors.Wrapf(err, "error getting volume ID for backup %q, PersistentVolume %q", backupName, name)
 	}
 	// no volumeID / nil error means unsupported PV source
 	if volumeID == "" {

pkg/client/client.go

@@ -20,6 +20,8 @@ import (
 	"fmt"
 	"runtime"
 
+	"github.com/pkg/errors"
+
 	"k8s.io/client-go/rest"
 	"k8s.io/client-go/tools/clientcmd"
 
@@ -33,7 +35,7 @@ func Config(kubeconfig, baseName string) (*rest.Config, error) {
 	loader.ExplicitPath = kubeconfig
 	clientConfig, err := clientcmd.BuildConfigFromKubeconfigGetter("", loader.Load)
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	clientConfig.UserAgent = buildUserAgent(

pkg/client/dynamic.go

@@ -17,6 +17,8 @@ limitations under the License.
 package client
 
 import (
+	"github.com/pkg/errors"
+
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"k8s.io/apimachinery/pkg/apis/meta/v1/unstructured"
 	"k8s.io/apimachinery/pkg/runtime"
@@ -51,7 +53,7 @@ func NewDynamicFactory(clientPool dynamic.ClientPool) DynamicFactory {
 func (f *dynamicFactory) ClientForGroupVersionResource(gvr schema.GroupVersionResource, resource metav1.APIResource, namespace string) (Dynamic, error) {
 	dynamicClient, err := f.clientPool.ClientForGroupVersionResource(gvr)
 	if err != nil {
-		return nil, err
+		return nil, errors.Wrapf(err, "error getting client for GroupVersionResource %s", gvr)
 	}
 
 	return &dynamicResourceClient{
@@ -62,7 +64,7 @@ func (f *dynamicFactory) ClientForGroupVersionResource(gvr schema.GroupVersionRe
 func (f *dynamicFactory) ClientForGroupVersionKind(gvk schema.GroupVersionKind, resource metav1.APIResource, namespace string) (Dynamic, error) {
 	dynamicClient, err := f.clientPool.ClientForGroupVersionKind(gvk)
 	if err != nil {
-		return nil, err
+		return nil, errors.Wrapf(err, "error getting client for GroupVersionKind %s", gvk)
 	}
 
 	return &dynamicResourceClient{

pkg/client/factory.go

@@ -17,6 +17,7 @@ limitations under the License.
 package client
 
 import (
+	"github.com/pkg/errors"
 	"github.com/spf13/pflag"
 
 	"github.com/heptio/ark/pkg/generated/clientset"
@@ -60,7 +61,7 @@ func (f *factory) Client() (clientset.Interface, error) {
 
 	arkClient, err := clientset.NewForConfig(clientConfig)
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 	return arkClient, nil
 }

pkg/cloudprovider/aws/block_storage_adapter.go

@@ -17,12 +17,10 @@ limitations under the License.
 package aws
 
 import (
-	"errors"
-	"fmt"
-
 	"github.com/aws/aws-sdk-go/aws"
 	"github.com/aws/aws-sdk-go/aws/session"
 	"github.com/aws/aws-sdk-go/service/ec2"
+	"github.com/pkg/errors"
 
 	"k8s.io/apimachinery/pkg/util/sets"
 
@@ -38,11 +36,11 @@ type blockStorageAdapter struct {
 func getSession(config *aws.Config) (*session.Session, error) {
 	sess, err := session.NewSession(config)
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	if _, err := sess.Config.Credentials.Get(); err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	return sess, nil
@@ -83,7 +81,7 @@ func (op *blockStorageAdapter) CreateVolumeFromSnapshot(snapshotID, volumeType,
 
 	res, err := op.ec2.CreateVolume(req)
 	if err != nil {
-		return "", err
+		return "", errors.WithStack(err)
 	}
 
 	return *res.VolumeId, nil
@@ -96,11 +94,11 @@ func (op *blockStorageAdapter) GetVolumeInfo(volumeID, volumeAZ string) (string,
 
 	res, err := op.ec2.DescribeVolumes(req)
 	if err != nil {
-		return "", nil, err
+		return "", nil, errors.WithStack(err)
 	}
 
 	if len(res.Volumes) != 1 {
-		return "", nil, fmt.Errorf("Expected one volume from DescribeVolumes for volume ID %v, got %v", volumeID, len(res.Volumes))
+		return "", nil, errors.Errorf("Expected one volume from DescribeVolumes for volume ID %v, got %v", volumeID, len(res.Volumes))
 	}
 
 	vol := res.Volumes[0]
@@ -128,10 +126,10 @@ func (op *blockStorageAdapter) IsVolumeReady(volumeID, volumeAZ string) (ready b
 
 	res, err := op.ec2.DescribeVolumes(req)
 	if err != nil {
-		return false, err
+		return false, errors.WithStack(err)
 	}
 	if len(res.Volumes) != 1 {
-		return false, fmt.Errorf("Expected one volume from DescribeVolumes for volume ID %v, got %v", volumeID, len(res.Volumes))
+		return false, errors.Errorf("Expected one volume from DescribeVolumes for volume ID %v, got %v", volumeID, len(res.Volumes))
 	}
 
 	return *res.Volumes[0].State == ec2.VolumeStateAvailable, nil
@@ -157,7 +155,7 @@ func (op *blockStorageAdapter) ListSnapshots(tagFilters map[string]string) ([]st
 		return !lastPage
 	})
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	return ret, nil
@@ -170,7 +168,7 @@ func (op *blockStorageAdapter) CreateSnapshot(volumeID, volumeAZ string, tags ma
 
 	res, err := op.ec2.CreateSnapshot(req)
 	if err != nil {
-		return "", err
+		return "", errors.WithStack(err)
 	}
 
 	tagsReq := &ec2.CreateTagsInput{}
@@ -190,7 +188,7 @@ func (op *blockStorageAdapter) CreateSnapshot(volumeID, volumeAZ string, tags ma
 
 	_, err = op.ec2.CreateTags(tagsReq)
 
-	return *res.SnapshotId, err
+	return *res.SnapshotId, errors.WithStack(err)
 }
 
 func (op *blockStorageAdapter) DeleteSnapshot(snapshotID string) error {
@@ -200,5 +198,5 @@ func (op *blockStorageAdapter) DeleteSnapshot(snapshotID string) error {
 
 	_, err := op.ec2.DeleteSnapshot(req)
 
-	return err
+	return errors.WithStack(err)
 }

pkg/cloudprovider/aws/object_storage_adapter.go

@@ -17,14 +17,13 @@ limitations under the License.
 package aws
 
 import (
-	"errors"
 	"io"
 	"time"
 
 	"github.com/aws/aws-sdk-go/aws"
 	"github.com/aws/aws-sdk-go/aws/endpoints"
 	"github.com/aws/aws-sdk-go/service/s3"
-	"github.com/golang/glog"
+	"github.com/pkg/errors"
 
 	"github.com/heptio/ark/pkg/cloudprovider"
 )
@@ -85,7 +84,7 @@ func (op *objectStorageAdapter) PutObject(bucket string, key string, body io.Rea
 
 	_, err := op.s3.PutObject(req)
 
-	return err
+	return errors.Wrapf(err, "error putting object %s", key)
 }
 
 func (op *objectStorageAdapter) GetObject(bucket string, key string) (io.ReadCloser, error) {
@@ -96,7 +95,7 @@ func (op *objectStorageAdapter) GetObject(bucket string, key string) (io.ReadClo
 
 	res, err := op.s3.GetObject(req)
 	if err != nil {
-		return nil, err
+		return nil, errors.Wrapf(err, "error getting object %s", key)
 	}
 
 	return res.Body, nil
@@ -117,7 +116,7 @@ func (op *objectStorageAdapter) ListCommonPrefixes(bucket string, delimiter stri
 	})
 
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	return ret, nil
@@ -138,7 +137,7 @@ func (op *objectStorageAdapter) ListObjects(bucket, prefix string) ([]string, er
 	})
 
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	return ret, nil
@@ -152,11 +151,10 @@ func (op *objectStorageAdapter) DeleteObject(bucket string, key string) error {
 
 	_, err := op.s3.DeleteObject(req)
 
-	return err
+	return errors.Wrapf(err, "error deleting object %s", key)
 }
 
 func (op *objectStorageAdapter) CreateSignedURL(bucket, key string, ttl time.Duration) (string, error) {
-	glog.V(4).Infof("CreateSignedURL: bucket=%s, key=%s, ttl=%d", bucket, key, ttl)
 	req, _ := op.s3.GetObjectRequest(&s3.GetObjectInput{
 		Bucket: aws.String(bucket),
 		Key:    aws.String(key),

pkg/cloudprovider/azure/block_storage_adapter.go

@@ -18,7 +18,6 @@ package azure
 
 import (
 	"context"
-	"errors"
 	"fmt"
 	"os"
 	"time"
@@ -28,6 +27,7 @@ import (
 	"github.com/Azure/azure-sdk-for-go/arm/resources/subscriptions"
 	"github.com/Azure/go-autorest/autorest"
 	"github.com/Azure/go-autorest/autorest/azure"
+	"github.com/pkg/errors"
 	"github.com/satori/uuid"
 
 	"github.com/heptio/ark/pkg/cloudprovider"
@@ -85,7 +85,7 @@ func NewBlockStorageAdapter(location string, apiTimeout time.Duration) (cloudpro
 
 	spt, err := helpers.NewServicePrincipalTokenFromCredentials(cfg, azure.PublicCloud.ResourceManagerEndpoint)
 	if err != nil {
-		return nil, fmt.Errorf("error creating new service principal: %v", err)
+		return nil, errors.Wrap(err, "error creating new service principal token")
 	}
 
 	disksClient := disk.NewDisksClient(cfg[azureSubscriptionIDKey])
@@ -101,7 +101,7 @@ func NewBlockStorageAdapter(location string, apiTimeout time.Duration) (cloudpro
 
 	locs, err := groupClient.ListLocations(cfg[azureSubscriptionIDKey])
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	if locs.Value == nil {
@@ -117,7 +117,7 @@ func NewBlockStorageAdapter(location string, apiTimeout time.Duration) (cloudpro
 	}
 
 	if !locationExists {
-		return nil, fmt.Errorf("location %q not found", location)
+		return nil, errors.Errorf("location %q not found", location)
 	}
 
 	return &blockStorageAdapter{
@@ -154,7 +154,7 @@ func (op *blockStorageAdapter) CreateVolumeFromSnapshot(snapshotID, volumeType,
 	err := <-errChan
 
 	if err != nil {
-		return "", err
+		return "", errors.WithStack(err)
 	}
 	return diskName, nil
 }
@@ -162,7 +162,7 @@ func (op *blockStorageAdapter) CreateVolumeFromSnapshot(snapshotID, volumeType,
 func (op *blockStorageAdapter) GetVolumeInfo(volumeID, volumeAZ string) (string, *int64, error) {
 	res, err := op.disks.Get(op.resourceGroup, volumeID)
 	if err != nil {
-		return "", nil, err
+		return "", nil, errors.WithStack(err)
 	}
 
 	return string(res.AccountType), nil, nil
@@ -171,7 +171,7 @@ func (op *blockStorageAdapter) GetVolumeInfo(volumeID, volumeAZ string) (string,
 func (op *blockStorageAdapter) IsVolumeReady(volumeID, volumeAZ string) (ready bool, err error) {
 	res, err := op.disks.Get(op.resourceGroup, volumeID)
 	if err != nil {
-		return false, err
+		return false, errors.WithStack(err)
 	}
 
 	if res.ProvisioningState == nil {
@@ -184,7 +184,7 @@ func (op *blockStorageAdapter) IsVolumeReady(volumeID, volumeAZ string) (ready b
 func (op *blockStorageAdapter) ListSnapshots(tagFilters map[string]string) ([]string, error) {
 	res, err := op.snaps.ListByResourceGroup(op.resourceGroup)
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	if res.Value == nil {
@@ -252,7 +252,7 @@ func (op *blockStorageAdapter) CreateSnapshot(volumeID, volumeAZ string, tags ma
 	err := <-errChan
 
 	if err != nil {
-		return "", err
+		return "", errors.WithStack(err)
 	}
 
 	return snapshotName, nil
@@ -266,7 +266,7 @@ func (op *blockStorageAdapter) DeleteSnapshot(snapshotID string) error {
 
 	err := <-errChan
 
-	return err
+	return errors.WithStack(err)
 }
 
 func getFullDiskName(subscription string, resourceGroup string, diskName string) string {

pkg/cloudprovider/azure/object_storage_adapter.go

@@ -17,12 +17,12 @@ limitations under the License.
 package azure
 
 import (
-	"fmt"
 	"io"
 	"strings"
 	"time"
 
 	"github.com/Azure/azure-sdk-for-go/storage"
+	"github.com/pkg/errors"
 
 	"github.com/heptio/ark/pkg/cloudprovider"
 )
@@ -40,7 +40,7 @@ func NewObjectStorageAdapter() (cloudprovider.ObjectStorageAdapter, error) {
 
 	storageClient, err := storage.NewBasicClient(cfg[azureStorageAccountIDKey], cfg[azureStorageKeyKey])
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	blobClient := storageClient.GetBlobService()
@@ -65,16 +65,16 @@ func (op *objectStorageAdapter) PutObject(bucket string, key string, body io.Rea
 	// length here is ugly. refactor to make this better.
 	len, err := body.Seek(0, io.SeekEnd)
 	if err != nil {
-		return err
+		return errors.WithStack(err)
 	}
 
 	blob.Properties.ContentLength = len
 
 	if _, err := body.Seek(0, 0); err != nil {
-		return err
+		return errors.WithStack(err)
 	}
 
-	return blob.CreateBlockBlobFromReader(body, nil)
+	return errors.WithStack(blob.CreateBlockBlobFromReader(body, nil))
 }
 
 func (op *objectStorageAdapter) GetObject(bucket string, key string) (io.ReadCloser, error) {
@@ -90,7 +90,7 @@ func (op *objectStorageAdapter) GetObject(bucket string, key string) (io.ReadClo
 
 	res, err := blob.Get(nil)
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	return res, nil
@@ -108,7 +108,7 @@ func (op *objectStorageAdapter) ListCommonPrefixes(bucket string, delimiter stri
 
 	res, err := container.ListBlobs(params)
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	// Azure returns prefixes inclusive of the last delimiter. We need to strip
@@ -133,7 +133,7 @@ func (op *objectStorageAdapter) ListObjects(bucket, prefix string) ([]string, er
 
 	res, err := container.ListBlobs(params)
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	ret := make([]string, 0, len(res.Blobs))
@@ -155,7 +155,7 @@ func (op *objectStorageAdapter) DeleteObject(bucket string, key string) error {
 		return err
 	}
 
-	return blob.Delete(nil)
+	return errors.WithStack(blob.Delete(nil))
 }
 
 const sasURIReadPermission = "r"
@@ -177,7 +177,7 @@ func (op *objectStorageAdapter) CreateSignedURL(bucket, key string, ttl time.Dur
 func getContainerReference(blobClient *storage.BlobStorageClient, bucket string) (*storage.Container, error) {
 	container := blobClient.GetContainerReference(bucket)
 	if container == nil {
-		return nil, fmt.Errorf("unable to get container reference for bucket %v", bucket)
+		return nil, errors.Errorf("unable to get container reference for bucket %v", bucket)
 	}
 
 	return container, nil
@@ -186,7 +186,7 @@ func getContainerReference(blobClient *storage.BlobStorageClient, bucket string)
 func getBlobReference(container *storage.Container, key string) (*storage.Blob, error) {
 	blob := container.GetBlobReference(key)
 	if blob == nil {
-		return nil, fmt.Errorf("unable to get blob reference for key %v", key)
+		return nil, errors.Errorf("unable to get blob reference for key %v", key)
 	}
 
 	return blob, nil

pkg/cloudprovider/backup_cache.go

@@ -21,7 +21,7 @@ import (
 	"sync"
 	"time"
 
-	"github.com/golang/glog"
+	"github.com/sirupsen/logrus"
 
 	"k8s.io/apimachinery/pkg/util/wait"
 
@@ -41,15 +41,17 @@ type backupCache struct {
 	// This doesn't really need to be a map right now, but if we ever move to supporting multiple
 	// buckets, this will be ready for it.
 	buckets map[string]*backupCacheBucket
+	logger  *logrus.Logger
 }
 
 var _ BackupGetter = &backupCache{}
 
 // NewBackupCache returns a new backup cache that refreshes from delegate every resyncPeriod.
-func NewBackupCache(ctx context.Context, delegate BackupGetter, resyncPeriod time.Duration) BackupGetter {
+func NewBackupCache(ctx context.Context, delegate BackupGetter, resyncPeriod time.Duration, logger *logrus.Logger) BackupGetter {
 	c := &backupCache{
 		delegate: delegate,
 		buckets:  make(map[string]*backupCacheBucket),
+		logger:   logger,
 	}
 
 	// Start the goroutine to refresh all buckets every resyncPeriod. This stops when ctx.Done() is
@@ -64,10 +66,10 @@ func (c *backupCache) refresh() {
 	c.lock.Lock()
 	defer c.lock.Unlock()
 
-	glog.V(4).Infof("refreshing all cached backup lists from object storage")
+	c.logger.Debug("refreshing all cached backup lists from object storage")
 
 	for bucketName, bucket := range c.buckets {
-		glog.V(4).Infof("refreshing bucket %q", bucketName)
+		c.logger.WithField("bucket", bucketName).Debug("Refreshing bucket")
 		bucket.backups, bucket.error = c.delegate.GetAllBackups(bucketName)
 	}
 }
@@ -76,12 +78,15 @@ func (c *backupCache) GetAllBackups(bucketName string) ([]*v1.Backup, error) {
 	c.lock.RLock()
 	bucket, found := c.buckets[bucketName]
 	c.lock.RUnlock()
+
+	logContext := c.logger.WithField("bucket", bucketName)
+
 	if found {
-		glog.V(4).Infof("returning cached backup list for bucket %q", bucketName)
+		logContext.Debug("Returning cached backup list")
 		return bucket.backups, bucket.error
 	}
 
-	glog.V(4).Infof("bucket %q is not in cache - doing a live lookup", bucketName)
+	logContext.Debug("Bucket is not in cache - doing a live lookup")
 
 	backups, err := c.delegate.GetAllBackups(bucketName)
 	c.lock.Lock()

pkg/cloudprovider/backup_cache_test.go

@@ -22,6 +22,7 @@ import (
 	"testing"
 	"time"
 
+	testlogger "github.com/sirupsen/logrus/hooks/test"
 	"github.com/stretchr/testify/assert"
 
 	"github.com/heptio/ark/pkg/apis/ark/v1"
@@ -29,12 +30,15 @@ import (
 )
 
 func TestNewBackupCache(t *testing.T) {
-	delegate := &test.FakeBackupService{}
 
-	ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
+	var (
+		delegate    = &test.FakeBackupService{}
+		ctx, cancel = context.WithTimeout(context.Background(), 5*time.Second)
+		logger, _   = testlogger.NewNullLogger()
+	)
 	defer cancel()
 
-	c := NewBackupCache(ctx, delegate, 100*time.Millisecond)
+	c := NewBackupCache(ctx, delegate, 100*time.Millisecond, logger)
 
 	// nothing in cache, live lookup
 	bucket1 := []*v1.Backup{
@@ -99,7 +103,10 @@ func TestNewBackupCache(t *testing.T) {
 }
 
 func TestBackupCacheRefresh(t *testing.T) {
-	delegate := &test.FakeBackupService{}
+	var (
+		delegate  = &test.FakeBackupService{}
+		logger, _ = testlogger.NewNullLogger()
+	)
 
 	c := &backupCache{
 		delegate: delegate,
@@ -107,6 +114,7 @@ func TestBackupCacheRefresh(t *testing.T) {
 			"bucket1": {},
 			"bucket2": {},
 		},
+		logger: logger,
 	}
 
 	bucket1 := []*v1.Backup{
@@ -127,12 +135,14 @@ func TestBackupCacheRefresh(t *testing.T) {
 }
 
 func TestBackupCacheGetAllBackupsUsesCacheIfPresent(t *testing.T) {
-	delegate := &test.FakeBackupService{}
-
-	bucket1 := []*v1.Backup{
-		test.NewTestBackup().WithName("backup1").Backup,
-		test.NewTestBackup().WithName("backup2").Backup,
-	}
+	var (
+		delegate  = &test.FakeBackupService{}
+		logger, _ = testlogger.NewNullLogger()
+		bucket1   = []*v1.Backup{
+			test.NewTestBackup().WithName("backup1").Backup,
+			test.NewTestBackup().WithName("backup2").Backup,
+		}
+	)
 
 	c := &backupCache{
 		delegate: delegate,
@@ -141,6 +151,7 @@ func TestBackupCacheGetAllBackupsUsesCacheIfPresent(t *testing.T) {
 				backups: bucket1,
 			},
 		},
+		logger: logger,
 	}
 
 	bucket2 := []*v1.Backup{

pkg/cloudprovider/backup_service.go

@@ -24,10 +24,11 @@ import (
 	"strings"
 	"time"
 
-	"github.com/golang/glog"
+	"github.com/pkg/errors"
+	"github.com/sirupsen/logrus"
 
 	"k8s.io/apimachinery/pkg/runtime"
-	"k8s.io/apimachinery/pkg/util/errors"
+	kerrors "k8s.io/apimachinery/pkg/util/errors"
 
 	api "github.com/heptio/ark/pkg/apis/ark/v1"
 	"github.com/heptio/ark/pkg/generated/clientset/scheme"
@@ -92,16 +93,18 @@ func getRestoreLogKey(backup, restore string) string {
 type backupService struct {
 	objectStorage ObjectStorageAdapter
 	decoder       runtime.Decoder
+	logger        *logrus.Logger
 }
 
 var _ BackupService = &backupService{}
 var _ BackupGetter = &backupService{}
 
 // NewBackupService creates a backup service using the provided object storage adapter
-func NewBackupService(objectStorage ObjectStorageAdapter) BackupService {
+func NewBackupService(objectStorage ObjectStorageAdapter, logger *logrus.Logger) BackupService {
 	return &backupService{
 		objectStorage: objectStorage,
 		decoder:       scheme.Codecs.UniversalDecoder(api.SchemeGroupVersion),
+		logger:        logger,
 	}
 }
 
@@ -118,14 +121,17 @@ func (br *backupService) UploadBackup(bucket, backupName string, metadata, backu
 		// try to delete the metadata file since the data upload failed
 		deleteErr := br.objectStorage.DeleteObject(bucket, metadataKey)
 
-		return errors.NewAggregate([]error{err, deleteErr})
+		return kerrors.NewAggregate([]error{err, deleteErr})
 	}
 
 	// uploading log file is best-effort; if it fails, we log the error but call the overall upload a
 	// success
 	logKey := getBackupLogKey(backupName)
 	if err := br.objectStorage.PutObject(bucket, logKey, log); err != nil {
-		glog.Errorf("error uploading %s/%s: %v", bucket, logKey, err)
+		br.logger.WithError(err).WithFields(logrus.Fields{
+			"bucket": bucket,
+			"key":    logKey,
+		}).Error("Error uploading log file")
 	}
 
 	return nil
@@ -149,7 +155,7 @@ func (br *backupService) GetAllBackups(bucket string) ([]*api.Backup, error) {
 	for _, backupDir := range prefixes {
 		backup, err := br.GetBackup(bucket, backupDir)
 		if err != nil {
-			glog.Errorf("Error reading backup directory %s: %v", backupDir, err)
+			br.logger.WithError(err).WithField("dir", backupDir).Error("Error reading backup directory")
 			continue
 		}
 
@@ -170,17 +176,17 @@ func (br *backupService) GetBackup(bucket, name string) (*api.Backup, error) {
 
 	data, err := ioutil.ReadAll(res)
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	obj, _, err := br.decoder.Decode(data, nil, nil)
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	backup, ok := obj.(*api.Backup)
 	if !ok {
-		return nil, fmt.Errorf("unexpected type for %s/%s: %T", bucket, key, obj)
+		return nil, errors.Errorf("unexpected type for %s/%s: %T", bucket, key, obj)
 	}
 
 	return backup, nil
@@ -194,13 +200,16 @@ func (br *backupService) DeleteBackupDir(bucket, backupName string) error {
 
 	var errs []error
 	for _, key := range objects {
-		glog.V(4).Infof("Trying to delete bucket=%s, key=%s", bucket, key)
+		br.logger.WithFields(logrus.Fields{
+			"bucket": bucket,
+			"key":    key,
+		}).Debug("Trying to delete object")
 		if err := br.objectStorage.DeleteObject(bucket, key); err != nil {
 			errs = append(errs, err)
 		}
 	}
 
-	return errors.NewAggregate(errs)
+	return errors.WithStack(kerrors.NewAggregate(errs))
 }
 
 func (br *backupService) CreateSignedURL(target api.DownloadTarget, bucket string, ttl time.Duration) (string, error) {
@@ -218,7 +227,7 @@ func (br *backupService) CreateSignedURL(target api.DownloadTarget, bucket strin
 		backup := target.Name[0:i]
 		return br.objectStorage.CreateSignedURL(bucket, getRestoreLogKey(backup, target.Name), ttl)
 	default:
-		return "", fmt.Errorf("unsupported download target kind %q", target.Kind)
+		return "", errors.Errorf("unsupported download target kind %q", target.Kind)
 	}
 }
 
@@ -235,10 +244,15 @@ type cachedBackupService struct {
 
 // NewBackupServiceWithCachedBackupGetter returns a BackupService that uses a cache for
 // GetAllBackups().
-func NewBackupServiceWithCachedBackupGetter(ctx context.Context, delegate BackupService, resyncPeriod time.Duration) BackupService {
+func NewBackupServiceWithCachedBackupGetter(
+	ctx context.Context,
+	delegate BackupService,
+	resyncPeriod time.Duration,
+	logger *logrus.Logger,
+) BackupService {
 	return &cachedBackupService{
 		BackupService: delegate,
-		cache:         NewBackupCache(ctx, delegate, resyncPeriod),
+		cache:         NewBackupCache(ctx, delegate, resyncPeriod, logger),
 	}
 }
 

pkg/cloudprovider/backup_service_test.go

@@ -27,6 +27,7 @@ import (
 	"time"
 
 	testutil "github.com/heptio/ark/pkg/util/test"
+	testlogger "github.com/sirupsen/logrus/hooks/test"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 
@@ -80,10 +81,12 @@ func TestUploadBackup(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			objStore := &testutil.ObjectStorageAdapter{}
-
-			bucket := "test-bucket"
-			backupName := "test-backup"
+			var (
+				objStore   = &testutil.ObjectStorageAdapter{}
+				bucket     = "test-bucket"
+				backupName = "test-backup"
+				logger, _  = testlogger.NewNullLogger()
+			)
 
 			if test.metadata != nil {
 				objStore.On("PutObject", bucket, backupName+"/ark-backup.json", test.metadata).Return(test.metadataError)
@@ -98,7 +101,7 @@ func TestUploadBackup(t *testing.T) {
 				objStore.On("DeleteObject", bucket, backupName+"/ark-backup.json").Return(nil)
 			}
 
-			backupService := NewBackupService(objStore)
+			backupService := NewBackupService(objStore, logger)
 
 			err := backupService.UploadBackup(bucket, backupName, test.metadata, test.backup, test.log)
 
@@ -114,11 +117,15 @@ func TestUploadBackup(t *testing.T) {
 }
 
 func TestDownloadBackup(t *testing.T) {
-	o := &testutil.ObjectStorageAdapter{}
-	bucket := "b"
-	backup := "bak"
+	var (
+		o         = &testutil.ObjectStorageAdapter{}
+		bucket    = "b"
+		backup    = "bak"
+		logger, _ = testlogger.NewNullLogger()
+	)
 	o.On("GetObject", bucket, backup+"/"+backup+".tar.gz").Return(ioutil.NopCloser(strings.NewReader("foo")), nil)
-	s := NewBackupService(o)
+
+	s := NewBackupService(o, logger)
 	rc, err := s.DownloadBackup(bucket, backup)
 	require.NoError(t, err)
 	require.NotNil(t, rc)
@@ -147,11 +154,14 @@ func TestDeleteBackup(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			bucket := "bucket"
-			backup := "bak"
-			objects := []string{"bak/ark-backup.json", "bak/bak.tar.gz", "bak/bak.log.gz"}
+			var (
+				bucket    = "bucket"
+				backup    = "bak"
+				objects   = []string{"bak/ark-backup.json", "bak/bak.tar.gz", "bak/bak.log.gz"}
+				objStore  = &testutil.ObjectStorageAdapter{}
+				logger, _ = testlogger.NewNullLogger()
+			)
 
-			objStore := &testutil.ObjectStorageAdapter{}
 			objStore.On("ListObjects", bucket, backup+"/").Return(objects, test.listObjectsError)
 			for i, o := range objects {
 				var err error
@@ -162,7 +172,7 @@ func TestDeleteBackup(t *testing.T) {
 				objStore.On("DeleteObject", bucket, o).Return(err)
 			}
 
-			backupService := NewBackupService(objStore)
+			backupService := NewBackupService(objStore, logger)
 
 			err := backupService.DeleteBackupDir(bucket, backup)
 
@@ -218,14 +228,17 @@ func TestGetAllBackups(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			bucket := "bucket"
+			var (
+				bucket    = "bucket"
+				objStore  = &testutil.ObjectStorageAdapter{}
+				logger, _ = testlogger.NewNullLogger()
+			)
 
-			objStore := &testutil.ObjectStorageAdapter{}
 			objStore.On("ListCommonPrefixes", bucket, "/").Return([]string{"backup-1", "backup-2"}, nil)
 			objStore.On("GetObject", bucket, "backup-1/ark-backup.json").Return(ioutil.NopCloser(bytes.NewReader(test.storageData["backup-1/ark-backup.json"])), nil)
 			objStore.On("GetObject", bucket, "backup-2/ark-backup.json").Return(ioutil.NopCloser(bytes.NewReader(test.storageData["backup-2/ark-backup.json"])), nil)
 
-			backupService := NewBackupService(objStore)
+			backupService := NewBackupService(objStore, logger)
 
 			res, err := backupService.GetAllBackups(bucket)
 
@@ -295,8 +308,11 @@ func TestCreateSignedURL(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			objectStorage := &testutil.ObjectStorageAdapter{}
-			backupService := NewBackupService(objectStorage)
+			var (
+				objectStorage = &testutil.ObjectStorageAdapter{}
+				logger, _     = testlogger.NewNullLogger()
+				backupService = NewBackupService(objectStorage, logger)
+			)
 
 			target := api.DownloadTarget{
 				Kind: test.targetKind,

pkg/cloudprovider/gcp/block_storage_adapter.go

@@ -17,11 +17,10 @@ limitations under the License.
 package gcp
 
 import (
-	"errors"
-	"fmt"
 	"strings"
 	"time"
 
+	"github.com/pkg/errors"
 	uuid "github.com/satori/go.uuid"
 	"golang.org/x/oauth2"
 	"golang.org/x/oauth2/google"
@@ -46,22 +45,22 @@ func NewBlockStorageAdapter(project string) (cloudprovider.BlockStorageAdapter,
 
 	client, err := google.DefaultClient(oauth2.NoContext, compute.ComputeScope)
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	gce, err := compute.New(client)
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	// validate project
 	res, err := gce.Projects.Get(project).Do()
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	if res == nil {
-		return nil, fmt.Errorf("error getting project %q", project)
+		return nil, errors.Errorf("error getting project %q", project)
 	}
 
 	return &blockStorageAdapter{
@@ -73,7 +72,7 @@ func NewBlockStorageAdapter(project string) (cloudprovider.BlockStorageAdapter,
 func (op *blockStorageAdapter) CreateVolumeFromSnapshot(snapshotID, volumeType, volumeAZ string, iops *int64) (volumeID string, err error) {
 	res, err := op.gce.Snapshots.Get(op.project, snapshotID).Do()
 	if err != nil {
-		return "", err
+		return "", errors.WithStack(err)
 	}
 
 	disk := &compute.Disk{
@@ -83,7 +82,7 @@ func (op *blockStorageAdapter) CreateVolumeFromSnapshot(snapshotID, volumeType,
 	}
 
 	if _, err = op.gce.Disks.Insert(op.project, volumeAZ, disk).Do(); err != nil {
-		return "", err
+		return "", errors.WithStack(err)
 	}
 
 	return disk.Name, nil
@@ -92,7 +91,7 @@ func (op *blockStorageAdapter) CreateVolumeFromSnapshot(snapshotID, volumeType,
 func (op *blockStorageAdapter) GetVolumeInfo(volumeID, volumeAZ string) (string, *int64, error) {
 	res, err := op.gce.Disks.Get(op.project, volumeAZ, volumeID).Do()
 	if err != nil {
-		return "", nil, err
+		return "", nil, errors.WithStack(err)
 	}
 
 	return res.Type, nil, nil
@@ -101,7 +100,7 @@ func (op *blockStorageAdapter) GetVolumeInfo(volumeID, volumeAZ string) (string,
 func (op *blockStorageAdapter) IsVolumeReady(volumeID, volumeAZ string) (ready bool, err error) {
 	disk, err := op.gce.Disks.Get(op.project, volumeAZ, volumeID).Do()
 	if err != nil {
-		return false, err
+		return false, errors.WithStack(err)
 	}
 
 	// TODO can we consider a disk ready while it's in the RESTORING state?
@@ -124,7 +123,7 @@ func (op *blockStorageAdapter) ListSnapshots(tagFilters map[string]string) ([]st
 
 	res, err := op.gce.Snapshots.List(op.project).Filter(filter).Do()
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	ret := make([]string, 0, len(res.Items))
@@ -153,7 +152,7 @@ func (op *blockStorageAdapter) CreateSnapshot(volumeID, volumeAZ string, tags ma
 
 	_, err := op.gce.Disks.CreateSnapshot(op.project, volumeAZ, volumeID, &gceSnap).Do()
 	if err != nil {
-		return "", err
+		return "", errors.WithStack(err)
 	}
 
 	// the snapshot is not immediately available after creation for putting labels
@@ -165,7 +164,7 @@ func (op *blockStorageAdapter) CreateSnapshot(volumeID, volumeAZ string, tags ma
 		}
 		return false, nil
 	}); pollErr != nil {
-		return "", err
+		return "", errors.WithStack(err)
 	}
 
 	labels := &compute.GlobalSetLabelsRequest{
@@ -175,7 +174,7 @@ func (op *blockStorageAdapter) CreateSnapshot(volumeID, volumeAZ string, tags ma
 
 	_, err = op.gce.Snapshots.SetLabels(op.project, gceSnap.Name, labels).Do()
 	if err != nil {
-		return "", err
+		return "", errors.WithStack(err)
 	}
 
 	return gceSnap.Name, nil
@@ -184,5 +183,5 @@ func (op *blockStorageAdapter) CreateSnapshot(volumeID, volumeAZ string, tags ma
 func (op *blockStorageAdapter) DeleteSnapshot(snapshotID string) error {
 	_, err := op.gce.Snapshots.Delete(op.project, snapshotID).Do()
 
-	return err
+	return errors.WithStack(err)
 }

pkg/cloudprovider/gcp/object_storage_adapter.go

@@ -17,11 +17,11 @@ limitations under the License.
 package gcp
 
 import (
-	"errors"
 	"io"
 	"strings"
 	"time"
 
+	"github.com/pkg/errors"
 	"golang.org/x/oauth2"
 	"golang.org/x/oauth2/google"
 	// TODO switch to using newstorage
@@ -42,12 +42,12 @@ var _ cloudprovider.ObjectStorageAdapter = &objectStorageAdapter{}
 func NewObjectStorageAdapter(googleAccessID string, privateKey []byte) (cloudprovider.ObjectStorageAdapter, error) {
 	client, err := google.DefaultClient(oauth2.NoContext, storage.DevstorageReadWriteScope)
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	gcs, err := storage.New(client)
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	return &objectStorageAdapter{
@@ -64,13 +64,13 @@ func (op *objectStorageAdapter) PutObject(bucket string, key string, body io.Rea
 
 	_, err := op.gcs.Objects.Insert(bucket, obj).Media(body).Do()
 
-	return err
+	return errors.WithStack(err)
 }
 
 func (op *objectStorageAdapter) GetObject(bucket string, key string) (io.ReadCloser, error) {
 	res, err := op.gcs.Objects.Get(bucket, key).Download()
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	return res.Body, nil
@@ -79,7 +79,7 @@ func (op *objectStorageAdapter) GetObject(bucket string, key string) (io.ReadClo
 func (op *objectStorageAdapter) ListCommonPrefixes(bucket string, delimiter string) ([]string, error) {
 	res, err := op.gcs.Objects.List(bucket).Delimiter(delimiter).Do()
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	// GCP returns prefixes inclusive of the last delimiter. We need to strip
@@ -95,7 +95,7 @@ func (op *objectStorageAdapter) ListCommonPrefixes(bucket string, delimiter stri
 func (op *objectStorageAdapter) ListObjects(bucket, prefix string) ([]string, error) {
 	res, err := op.gcs.Objects.List(bucket).Prefix(prefix).Do()
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	ret := make([]string, 0, len(res.Items))
@@ -107,7 +107,7 @@ func (op *objectStorageAdapter) ListObjects(bucket, prefix string) ([]string, er
 }
 
 func (op *objectStorageAdapter) DeleteObject(bucket string, key string) error {
-	return op.gcs.Objects.Delete(bucket, key).Do()
+	return errors.Wrapf(op.gcs.Objects.Delete(bucket, key).Do(), "error deleting object %s", key)
 }
 
 func (op *objectStorageAdapter) CreateSignedURL(bucket, key string, ttl time.Duration) (string, error) {

pkg/cloudprovider/snapshot_service.go

@@ -17,8 +17,9 @@ limitations under the License.
 package cloudprovider
 
 import (
-	"fmt"
 	"time"
+
+	"github.com/pkg/errors"
 )
 
 // SnapshotService exposes Ark-specific operations for snapshotting and restoring block
@@ -82,7 +83,7 @@ func (sr *snapshotService) CreateVolumeFromSnapshot(snapshotID string, volumeTyp
 	for {
 		select {
 		case <-timeout.C:
-			return "", fmt.Errorf("timeout reached waiting for volume %v to be ready", volumeID)
+			return "", errors.Errorf("timeout reached waiting for volume %v to be ready", volumeID)
 		case <-ticker.C:
 			if ready, err := sr.blockStorage.IsVolumeReady(volumeID, volumeAZ); err == nil && ready {
 				return volumeID, nil

pkg/cmd/cli/backup/create.go

@@ -17,10 +17,10 @@ limitations under the License.
 package backup
 
 import (
-	"errors"
 	"fmt"
 	"time"
 
+	"github.com/pkg/errors"
 	"github.com/spf13/cobra"
 	"github.com/spf13/pflag"
 

pkg/cmd/cli/backup/download.go

@@ -17,12 +17,12 @@ limitations under the License.
 package backup
 
 import (
-	"errors"
 	"fmt"
 	"os"
 	"path/filepath"
 	"time"
 
+	"github.com/pkg/errors"
 	"github.com/spf13/cobra"
 	"github.com/spf13/pflag"
 
@@ -88,7 +88,7 @@ func (o *DownloadOptions) Complete(args []string) error {
 	if o.Output == "" {
 		path, err := os.Getwd()
 		if err != nil {
-			return fmt.Errorf("error getting current directory: %v", err)
+			return errors.Wrapf(err, "error getting current directory")
 		}
 		o.Output = filepath.Join(path, fmt.Sprintf("%s-data.tar.gz", o.Name))
 	}

pkg/cmd/cli/backup/logs.go

@@ -17,10 +17,10 @@ limitations under the License.
 package backup
 
 import (
-	"errors"
 	"os"
 	"time"
 
+	"github.com/pkg/errors"
 	"github.com/spf13/cobra"
 
 	"github.com/heptio/ark/pkg/apis/ark/v1"

pkg/cmd/cli/restore/create.go

@@ -17,10 +17,10 @@ limitations under the License.
 package restore
 
 import (
-	"errors"
 	"fmt"
 	"time"
 
+	"github.com/pkg/errors"
 	"github.com/spf13/cobra"
 	"github.com/spf13/pflag"
 

pkg/cmd/cli/restore/logs.go

@@ -17,10 +17,10 @@ limitations under the License.
 package restore
 
 import (
-	"errors"
 	"os"
 	"time"
 
+	"github.com/pkg/errors"
 	"github.com/spf13/cobra"
 
 	"github.com/heptio/ark/pkg/apis/ark/v1"

pkg/cmd/cli/schedule/create.go

@@ -17,9 +17,9 @@ limitations under the License.
 package schedule
 
 import (
-	"errors"
 	"fmt"
 
+	"github.com/pkg/errors"
 	"github.com/spf13/cobra"
 	"github.com/spf13/pflag"
 

pkg/cmd/server/server.go

@@ -25,10 +25,10 @@ import (
 	"sync"
 	"time"
 
-	"golang.org/x/oauth2/google"
-
-	"github.com/golang/glog"
+	"github.com/pkg/errors"
+	"github.com/sirupsen/logrus"
 	"github.com/spf13/cobra"
+	"golang.org/x/oauth2/google"
 
 	apierrors "k8s.io/apimachinery/pkg/api/errors"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
@@ -56,6 +56,7 @@ import (
 	"github.com/heptio/ark/pkg/restore"
 	"github.com/heptio/ark/pkg/restore/restorers"
 	"github.com/heptio/ark/pkg/util/kube"
+	"github.com/heptio/ark/pkg/util/logging"
 )
 
 func NewCommand() *cobra.Command {
@@ -66,7 +67,11 @@ func NewCommand() *cobra.Command {
 		Short: "Run the ark server",
 		Long:  "Run the ark server",
 		Run: func(c *cobra.Command, args []string) {
-			s, err := newServer(kubeconfig, fmt.Sprintf("%s-%s", c.Parent().Name(), c.Name()))
+			logger := logrus.New()
+			logger.Hooks.Add(&logging.ErrorLocationHook{})
+
+			s, err := newServer(kubeconfig, fmt.Sprintf("%s-%s", c.Parent().Name(), c.Name()), logger)
+
 			cmd.CheckError(err)
 
 			cmd.CheckError(s.run())
@@ -88,9 +93,10 @@ type server struct {
 	sharedInformerFactory informers.SharedInformerFactory
 	ctx                   context.Context
 	cancelFunc            context.CancelFunc
+	logger                *logrus.Logger
 }
 
-func newServer(kubeconfig, baseName string) (*server, error) {
+func newServer(kubeconfig, baseName string, logger *logrus.Logger) (*server, error) {
 	clientConfig, err := client.Config(kubeconfig, baseName)
 	if err != nil {
 		return nil, err
@@ -98,12 +104,12 @@ func newServer(kubeconfig, baseName string) (*server, error) {
 
 	kubeClient, err := kubernetes.NewForConfig(clientConfig)
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	arkClient, err := clientset.NewForConfig(clientConfig)
 	if err != nil {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
 	ctx, cancelFunc := context.WithCancel(context.Background())
@@ -116,6 +122,7 @@ func newServer(kubeconfig, baseName string) (*server, error) {
 		sharedInformerFactory: informers.NewSharedInformerFactory(arkClient, 0),
 		ctx:        ctx,
 		cancelFunc: cancelFunc,
+		logger:     logger,
 	}
 
 	return s, nil
@@ -135,10 +142,10 @@ func (s *server) run() error {
 	// separate object, and instead apply defaults to a clone.
 	copy, err := scheme.Scheme.DeepCopy(originalConfig)
 	if err != nil {
-		return err
+		return errors.WithStack(err)
 	}
 	config := copy.(*api.Config)
-	applyConfigDefaults(config)
+	applyConfigDefaults(config, s.logger)
 
 	s.watchConfig(originalConfig)
 
@@ -158,7 +165,9 @@ func (s *server) run() error {
 }
 
 func (s *server) ensureArkNamespace() error {
-	glog.Infof("Ensuring %s namespace exists for backups", api.DefaultNamespace)
+	logContext := s.logger.WithField("namespace", api.DefaultNamespace)
+
+	logContext.Info("Ensuring namespace exists for backups")
 	defaultNamespace := v1.Namespace{
 		ObjectMeta: metav1.ObjectMeta{
 			Name: api.DefaultNamespace,
@@ -166,16 +175,16 @@ func (s *server) ensureArkNamespace() error {
 	}
 
 	if created, err := kube.EnsureNamespaceExists(&defaultNamespace, s.kubeClient.CoreV1().Namespaces()); created {
-		glog.Infof("Namespace created")
+		logContext.Info("Namespace created")
 	} else if err != nil {
 		return err
 	}
-	glog.Infof("Namespace already exists")
+	logContext.Info("Namespace already exists")
 	return nil
 }
 
 func (s *server) loadConfig() (*api.Config, error) {
-	glog.Infof("Retrieving Ark configuration")
+	s.logger.Info("Retrieving Ark configuration")
 	var (
 		config *api.Config
 		err    error
@@ -186,12 +195,14 @@ func (s *server) loadConfig() (*api.Config, error) {
 			break
 		}
 		if !apierrors.IsNotFound(err) {
-			glog.Errorf("error retrieving configuration: %v", err)
+			s.logger.WithError(err).Error("Error retrieving configuration")
+		} else {
+			s.logger.Info("Configuration not found")
 		}
-		glog.Infof("Will attempt to retrieve configuration again in 5 seconds")
+		s.logger.Info("Will attempt to retrieve configuration again in 5 seconds")
 		time.Sleep(5 * time.Second)
 	}
-	glog.Infof("Successfully retrieved Ark configuration")
+	s.logger.Info("Successfully retrieved Ark configuration")
 	return config, nil
 }
 
@@ -209,7 +220,7 @@ var defaultResourcePriorities = []string{
 	"configmaps",
 }
 
-func applyConfigDefaults(c *api.Config) {
+func applyConfigDefaults(c *api.Config, logger *logrus.Logger) {
 	if c.GCSyncPeriod.Duration == 0 {
 		c.GCSyncPeriod.Duration = defaultGCSyncPeriod
 	}
@@ -224,9 +235,9 @@ func applyConfigDefaults(c *api.Config) {
 
 	if len(c.ResourcePriorities) == 0 {
 		c.ResourcePriorities = defaultResourcePriorities
-		glog.Infof("Using default resource priorities: %v", c.ResourcePriorities)
+		logger.WithField("priorities", c.ResourcePriorities).Info("Using default resource priorities")
 	} else {
-		glog.Infof("Using resource priorities from config: %v", c.ResourcePriorities)
+		logger.WithField("priorities", c.ResourcePriorities).Info("Using resource priorities from config")
 	}
 }
 
@@ -236,10 +247,10 @@ func (s *server) watchConfig(config *api.Config) {
 	s.sharedInformerFactory.Ark().V1().Configs().Informer().AddEventHandler(cache.ResourceEventHandlerFuncs{
 		UpdateFunc: func(oldObj, newObj interface{}) {
 			updated := newObj.(*api.Config)
-			glog.V(4).Infof("received updated config: %q", kube.NamespaceAndName(updated))
+			s.logger.WithField("name", kube.NamespaceAndName(updated)).Debug("received updated config")
 
 			if updated.Name != config.Name {
-				glog.V(5).Infof("config watch channel received other config %q", updated.Name)
+				s.logger.WithField("name", updated.Name).Debug("Config watch channel received other config")
 				return
 			}
 
@@ -256,7 +267,7 @@ func (s *server) watchConfig(config *api.Config) {
 			}
 
 			if !reflect.DeepEqual(config, updated) {
-				glog.Infof("Detected a config change. Gracefully shutting down")
+				s.logger.Info("Detected a config change. Gracefully shutting down")
 				s.cancelFunc()
 			}
 		},
@@ -264,23 +275,23 @@ func (s *server) watchConfig(config *api.Config) {
 }
 
 func (s *server) initBackupService(config *api.Config) error {
-	glog.Infof("Configuring cloud provider for backup service")
-	objectStorage, err := getObjectStorageProvider(config.BackupStorageProvider.CloudProviderConfig, "backupStorageProvider")
+	s.logger.Info("Configuring cloud provider for backup service")
+	objectStorage, err := getObjectStorageProvider(config.BackupStorageProvider.CloudProviderConfig, "backupStorageProvider", s.logger)
 	if err != nil {
 		return err
 	}
 
-	s.backupService = cloudprovider.NewBackupService(objectStorage)
+	s.backupService = cloudprovider.NewBackupService(objectStorage, s.logger)
 	return nil
 }
 
 func (s *server) initSnapshotService(config *api.Config) error {
 	if config.PersistentVolumeProvider == nil {
-		glog.Infof("PersistentVolumeProvider config not provided, volume snapshots and restores are disabled")
+		s.logger.Info("PersistentVolumeProvider config not provided, volume snapshots and restores are disabled")
 		return nil
 	}
 
-	glog.Infof("Configuring cloud provider for snapshot service")
+	s.logger.Info("Configuring cloud provider for snapshot service")
 	blockStorage, err := getBlockStorageProvider(*config.PersistentVolumeProvider, "persistentVolumeProvider")
 	if err != nil {
 		return err
@@ -313,14 +324,14 @@ func hasOneCloudProvider(cloudConfig api.CloudProviderConfig) bool {
 	return found
 }
 
-func getObjectStorageProvider(cloudConfig api.CloudProviderConfig, field string) (cloudprovider.ObjectStorageAdapter, error) {
+func getObjectStorageProvider(cloudConfig api.CloudProviderConfig, field string, logger *logrus.Logger) (cloudprovider.ObjectStorageAdapter, error) {
 	var (
 		objectStorage cloudprovider.ObjectStorageAdapter
 		err           error
 	)
 
 	if !hasOneCloudProvider(cloudConfig) {
-		return nil, fmt.Errorf("you must specify exactly one of aws, gcp, or azure for %s", field)
+		return nil, errors.Errorf("you must specify exactly one of aws, gcp, or azure for %s", field)
 	}
 
 	switch {
@@ -339,16 +350,16 @@ func getObjectStorageProvider(cloudConfig api.CloudProviderConfig, field string)
 			// Get the email and private key from the credentials file so we can pre-sign download URLs
 			creds, err := ioutil.ReadFile(credentialsFile)
 			if err != nil {
-				return nil, err
+				return nil, errors.WithStack(err)
 			}
 			jwtConfig, err := google.JWTConfigFromJSON(creds)
 			if err != nil {
-				return nil, err
+				return nil, errors.WithStack(err)
 			}
 			email = jwtConfig.Email
 			privateKey = jwtConfig.PrivateKey
 		} else {
-			glog.Warning("GOOGLE_APPLICATION_CREDENTIALS is undefined; some features such as downloading log files will not work")
+			logger.Warning("GOOGLE_APPLICATION_CREDENTIALS is undefined; some features such as downloading log files will not work")
 		}
 
 		objectStorage, err = gcp.NewObjectStorageAdapter(email, privateKey)
@@ -370,7 +381,7 @@ func getBlockStorageProvider(cloudConfig api.CloudProviderConfig, field string)
 	)
 
 	if !hasOneCloudProvider(cloudConfig) {
-		return nil, fmt.Errorf("you must specify exactly one of aws, gcp, or azure for %s", field)
+		return nil, errors.Errorf("you must specify exactly one of aws, gcp, or azure for %s", field)
 	}
 
 	switch {
@@ -397,17 +408,18 @@ func durationMin(a, b time.Duration) time.Duration {
 }
 
 func (s *server) runControllers(config *api.Config) error {
-	glog.Infof("Starting controllers")
+	s.logger.Info("Starting controllers")
 
 	ctx := s.ctx
 	var wg sync.WaitGroup
 
 	cloudBackupCacheResyncPeriod := durationMin(config.GCSyncPeriod.Duration, config.BackupSyncPeriod.Duration)
-	glog.Infof("Caching cloud backups every %s", cloudBackupCacheResyncPeriod)
+	s.logger.Infof("Caching cloud backups every %s", cloudBackupCacheResyncPeriod)
 	s.backupService = cloudprovider.NewBackupServiceWithCachedBackupGetter(
 		ctx,
 		s.backupService,
 		cloudBackupCacheResyncPeriod,
+		s.logger,
 	)
 
 	backupSyncController := controller.NewBackupSyncController(
@@ -415,6 +427,7 @@ func (s *server) runControllers(config *api.Config) error {
 		s.backupService,
 		config.BackupStorageProvider.Bucket,
 		config.BackupSyncPeriod.Duration,
+		s.logger,
 	)
 	wg.Add(1)
 	go func() {
@@ -422,14 +435,14 @@ func (s *server) runControllers(config *api.Config) error {
 		wg.Done()
 	}()
 
-	discoveryHelper, err := arkdiscovery.NewHelper(s.discoveryClient)
+	discoveryHelper, err := arkdiscovery.NewHelper(s.discoveryClient, s.logger)
 	if err != nil {
 		return err
 	}
 	go wait.Until(
 		func() {
 			if err := discoveryHelper.Refresh(); err != nil {
-				glog.Errorf("error refreshing discovery: %v", err)
+				s.logger.WithError(err).Error("Error refreshing discovery")
 			}
 		},
 		5*time.Minute,
@@ -437,7 +450,7 @@ func (s *server) runControllers(config *api.Config) error {
 	)
 
 	if config.RestoreOnlyMode {
-		glog.Infof("Restore only mode - not starting the backup, schedule or GC controllers")
+		s.logger.Info("Restore only mode - not starting the backup, schedule or GC controllers")
 	} else {
 		backupper, err := newBackupper(discoveryHelper, s.clientPool, s.backupService, s.snapshotService)
 		cmd.CheckError(err)
@@ -448,6 +461,7 @@ func (s *server) runControllers(config *api.Config) error {
 			s.backupService,
 			config.BackupStorageProvider.Bucket,
 			s.snapshotService != nil,
+			s.logger,
 		)
 		wg.Add(1)
 		go func() {
@@ -460,6 +474,7 @@ func (s *server) runControllers(config *api.Config) error {
 			s.arkClient.ArkV1(),
 			s.sharedInformerFactory.Ark().V1().Schedules(),
 			config.ScheduleSyncPeriod.Duration,
+			s.logger,
 		)
 		wg.Add(1)
 		go func() {
@@ -476,6 +491,7 @@ func (s *server) runControllers(config *api.Config) error {
 			s.arkClient.ArkV1(),
 			s.sharedInformerFactory.Ark().V1().Restores(),
 			s.arkClient.ArkV1(),
+			s.logger,
 		)
 		wg.Add(1)
 		go func() {
@@ -492,6 +508,7 @@ func (s *server) runControllers(config *api.Config) error {
 		config.ResourcePriorities,
 		s.arkClient.ArkV1(),
 		s.kubeClient,
+		s.logger,
 	)
 	cmd.CheckError(err)
 
@@ -504,6 +521,7 @@ func (s *server) runControllers(config *api.Config) error {
 		config.BackupStorageProvider.Bucket,
 		s.sharedInformerFactory.Ark().V1().Backups(),
 		s.snapshotService != nil,
+		s.logger,
 	)
 	wg.Add(1)
 	go func() {
@@ -516,6 +534,7 @@ func (s *server) runControllers(config *api.Config) error {
 		s.sharedInformerFactory.Ark().V1().DownloadRequests(),
 		s.backupService,
 		config.BackupStorageProvider.Bucket,
+		s.logger,
 	)
 	wg.Add(1)
 	go func() {
@@ -526,11 +545,11 @@ func (s *server) runControllers(config *api.Config) error {
 	// SHARED INFORMERS HAVE TO BE STARTED AFTER ALL CONTROLLERS
 	go s.sharedInformerFactory.Start(ctx.Done())
 
-	glog.Infof("Server started successfully")
+	s.logger.Info("Server started successfully")
 
 	<-ctx.Done()
 
-	glog.Info("Waiting for all controllers to shut down gracefully")
+	s.logger.Info("Waiting for all controllers to shut down gracefully")
 	wg.Wait()
 
 	return nil
@@ -568,14 +587,15 @@ func newRestorer(
 	resourcePriorities []string,
 	backupClient arkv1client.BackupsGetter,
 	kubeClient kubernetes.Interface,
+	logger *logrus.Logger,
 ) (restore.Restorer, error) {
 	restorers := map[string]restorers.ResourceRestorer{
 		"persistentvolumes":      restorers.NewPersistentVolumeRestorer(snapshotService),
 		"persistentvolumeclaims": restorers.NewPersistentVolumeClaimRestorer(),
 		"services":               restorers.NewServiceRestorer(),
 		"namespaces":             restorers.NewNamespaceRestorer(),
-		"pods":                   restorers.NewPodRestorer(),
-		"jobs":                   restorers.NewJobRestorer(),
+		"pods":                   restorers.NewPodRestorer(logger),
+		"jobs":                   restorers.NewJobRestorer(logger),
 	}
 
 	return restore.NewKubernetesRestorer(
@@ -586,5 +606,6 @@ func newRestorer(
 		resourcePriorities,
 		backupClient,
 		kubeClient.CoreV1().Namespaces(),
+		logger,
 	)
 }

pkg/cmd/server/server_test.go

@@ -20,16 +20,20 @@ import (
 	"testing"
 	"time"
 
+	"github.com/sirupsen/logrus/hooks/test"
 	"github.com/stretchr/testify/assert"
 
 	"github.com/heptio/ark/pkg/apis/ark/v1"
 )
 
 func TestApplyConfigDefaults(t *testing.T) {
-	c := &v1.Config{}
+	var (
+		logger, _ = test.NewNullLogger()
+		c         = &v1.Config{}
+	)
 
 	// test defaulting
-	applyConfigDefaults(c)
+	applyConfigDefaults(c, logger)
 	assert.Equal(t, defaultGCSyncPeriod, c.GCSyncPeriod.Duration)
 	assert.Equal(t, defaultBackupSyncPeriod, c.BackupSyncPeriod.Duration)
 	assert.Equal(t, defaultScheduleSyncPeriod, c.ScheduleSyncPeriod.Duration)
@@ -41,8 +45,7 @@ func TestApplyConfigDefaults(t *testing.T) {
 	c.ScheduleSyncPeriod.Duration = 3 * time.Minute
 	c.ResourcePriorities = []string{"a", "b"}
 
-	applyConfigDefaults(c)
-
+	applyConfigDefaults(c, logger)
 	assert.Equal(t, 5*time.Minute, c.GCSyncPeriod.Duration)
 	assert.Equal(t, 4*time.Minute, c.BackupSyncPeriod.Duration)
 	assert.Equal(t, 3*time.Minute, c.ScheduleSyncPeriod.Duration)

pkg/cmd/util/downloadrequest/downloadrequest.go

@@ -18,13 +18,14 @@ package downloadrequest
 
 import (
 	"compress/gzip"
-	"errors"
 	"fmt"
 	"io"
 	"io/ioutil"
 	"net/http"
 	"time"
 
+	"github.com/pkg/errors"
+
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"k8s.io/apimachinery/pkg/watch"
 
@@ -48,7 +49,7 @@ func Stream(client arkclientv1.DownloadRequestsGetter, name string, kind v1.Down
 
 	req, err := client.DownloadRequests(v1.DefaultNamespace).Create(req)
 	if err != nil {
-		return err
+		return errors.WithStack(err)
 	}
 	defer client.DownloadRequests(v1.DefaultNamespace).Delete(req.Name, nil)
 
@@ -59,7 +60,7 @@ func Stream(client arkclientv1.DownloadRequestsGetter, name string, kind v1.Down
 	}
 	watcher, err := client.DownloadRequests(v1.DefaultNamespace).Watch(listOptions)
 	if err != nil {
-		return err
+		return errors.WithStack(err)
 	}
 	defer watcher.Stop()
 
@@ -74,7 +75,7 @@ Loop:
 		case e := <-watcher.ResultChan():
 			updated, ok := e.Object.(*v1.DownloadRequest)
 			if !ok {
-				return fmt.Errorf("unexpected type %T", e.Object)
+				return errors.Errorf("unexpected type %T", e.Object)
 			}
 
 			if updated.Name != req.Name {
@@ -118,10 +119,10 @@ Loop:
 	if resp.StatusCode != http.StatusOK {
 		body, err := ioutil.ReadAll(resp.Body)
 		if err != nil {
-			return fmt.Errorf("request failed; unable to decode response body: %v", err)
+			return errors.Wrapf(err, "request failed; unable to decode response body")
 		}
 
-		return fmt.Errorf("request failed: %v", string(body))
+		return errors.Errorf("request failed: %v", string(body))
 	}
 
 	reader := resp.Body

pkg/cmd/util/flag/enum.go

@@ -17,7 +17,7 @@ limitations under the License.
 package flag
 
 import (
-	"fmt"
+	"github.com/pkg/errors"
 
 	"k8s.io/apimachinery/pkg/util/sets"
 )
@@ -51,7 +51,7 @@ func (e *Enum) String() string {
 // is not an allowed value.
 func (e *Enum) Set(s string) error {
 	if !e.allowedValues.Has(s) {
-		return fmt.Errorf("invalid value: %q", s)
+		return errors.Errorf("invalid value: %q", s)
 	}
 
 	e.value = s

pkg/cmd/util/flag/map.go

@@ -19,6 +19,8 @@ package flag
 import (
 	"fmt"
 	"strings"
+
+	"github.com/pkg/errors"
 )
 
 // Map is a Cobra-compatible wrapper for defining a flag containing
@@ -73,7 +75,7 @@ func (m *Map) Set(s string) error {
 	for _, part := range strings.Split(s, m.entryDelimiter) {
 		kvs := strings.SplitN(part, m.keyValueDelimiter, 2)
 		if len(kvs) != 2 {
-			return fmt.Errorf("error parsing %q", part)
+			return errors.Errorf("error parsing %q", part)
 		}
 		m.data[kvs[0]] = kvs[1]
 	}

pkg/cmd/util/output/output.go

@@ -20,6 +20,7 @@ import (
 	"fmt"
 	"os"
 
+	"github.com/pkg/errors"
 	"github.com/spf13/cobra"
 	"github.com/spf13/pflag"
 
@@ -85,7 +86,7 @@ func validateOutputFlag(cmd *cobra.Command) error {
 	switch output {
 	case "", "table", "json", "yaml":
 	default:
-		return fmt.Errorf("invalid output format %q - valid values are 'table', 'json', and 'yaml'", output)
+		return errors.Errorf("invalid output format %q - valid values are 'table', 'json', and 'yaml'", output)
 	}
 	return nil
 }
@@ -105,7 +106,7 @@ func PrintWithFormat(c *cobra.Command, obj runtime.Object) (bool, error) {
 		return printEncoded(obj, format)
 	}
 
-	return false, fmt.Errorf("unsupported output format %q; valid values are 'table', 'json', and 'yaml'", format)
+	return false, errors.Errorf("unsupported output format %q; valid values are 'table', 'json', and 'yaml'", format)
 }
 
 func printEncoded(obj runtime.Object, format string) (bool, error) {

pkg/controller/backup_controller.go

@@ -19,14 +19,14 @@ package controller
 import (
 	"bytes"
 	"context"
-	"errors"
 	"fmt"
 	"io/ioutil"
 	"os"
 	"sync"
 	"time"
 
-	"github.com/golang/glog"
+	"github.com/pkg/errors"
+	"github.com/sirupsen/logrus"
 
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"k8s.io/apimachinery/pkg/util/clock"
@@ -44,6 +44,7 @@ import (
 	listers "github.com/heptio/ark/pkg/generated/listers/ark/v1"
 	"github.com/heptio/ark/pkg/util/collections"
 	"github.com/heptio/ark/pkg/util/encode"
+	kubeutil "github.com/heptio/ark/pkg/util/kube"
 )
 
 const backupVersion = 1
@@ -53,14 +54,13 @@ type backupController struct {
 	backupService    cloudprovider.BackupService
 	bucket           string
 	pvProviderExists bool
-
-	lister       listers.BackupLister
-	listerSynced cache.InformerSynced
-	client       arkv1client.BackupsGetter
-	syncHandler  func(backupName string) error
-	queue        workqueue.RateLimitingInterface
-
-	clock clock.Clock
+	lister           listers.BackupLister
+	listerSynced     cache.InformerSynced
+	client           arkv1client.BackupsGetter
+	syncHandler      func(backupName string) error
+	queue            workqueue.RateLimitingInterface
+	clock            clock.Clock
+	logger           *logrus.Logger
 }
 
 func NewBackupController(
@@ -70,19 +70,19 @@ func NewBackupController(
 	backupService cloudprovider.BackupService,
 	bucket string,
 	pvProviderExists bool,
+	logger *logrus.Logger,
 ) Interface {
 	c := &backupController{
 		backupper:        backupper,
 		backupService:    backupService,
 		bucket:           bucket,
 		pvProviderExists: pvProviderExists,
-
-		lister:       backupInformer.Lister(),
-		listerSynced: backupInformer.Informer().HasSynced,
-		client:       client,
-		queue:        workqueue.NewNamedRateLimitingQueue(workqueue.DefaultControllerRateLimiter(), "backup"),
-
-		clock: &clock.RealClock{},
+		lister:           backupInformer.Lister(),
+		listerSynced:     backupInformer.Informer().HasSynced,
+		client:           client,
+		queue:            workqueue.NewNamedRateLimitingQueue(workqueue.DefaultControllerRateLimiter(), "backup"),
+		clock:            &clock.RealClock{},
+		logger:           logger,
 	}
 
 	c.syncHandler = c.processBackup
@@ -96,13 +96,16 @@ func NewBackupController(
 				case "", api.BackupPhaseNew:
 					// only process new backups
 				default:
-					glog.V(4).Infof("Backup %s/%s has phase %s - skipping", backup.Namespace, backup.Name, backup.Status.Phase)
+					c.logger.WithFields(logrus.Fields{
+						"backup": kubeutil.NamespaceAndName(backup),
+						"phase":  backup.Status.Phase,
+					}).Debug("Backup is not new, skipping")
 					return
 				}
 
 				key, err := cache.MetaNamespaceKeyFunc(backup)
 				if err != nil {
-					glog.Errorf("error creating queue key for %#v: %v", backup, err)
+					c.logger.WithError(err).WithField("backup", backup).Error("Error creating queue key, item not added to queue")
 					return
 				}
 				c.queue.Add(key)
@@ -120,7 +123,7 @@ func (controller *backupController) Run(ctx context.Context, numWorkers int) err
 	var wg sync.WaitGroup
 
 	defer func() {
-		glog.Infof("Waiting for workers to finish their work")
+		controller.logger.Info("Waiting for workers to finish their work")
 
 		controller.queue.ShutDown()
 
@@ -129,17 +132,18 @@ func (controller *backupController) Run(ctx context.Context, numWorkers int) err
 		// we want to shut down the queue via defer and not at the end of the body.
 		wg.Wait()
 
-		glog.Infof("All workers have finished")
+		controller.logger.Info("All workers have finished")
+
 	}()
 
-	glog.Info("Starting BackupController")
-	defer glog.Infof("Shutting down BackupController")
+	controller.logger.Info("Starting BackupController")
+	defer controller.logger.Info("Shutting down BackupController")
 
-	glog.Info("Waiting for caches to sync")
+	controller.logger.Info("Waiting for caches to sync")
 	if !cache.WaitForCacheSync(ctx.Done(), controller.listerSynced) {
 		return errors.New("timed out waiting for caches to sync")
 	}
-	glog.Info("Caches are synced")
+	controller.logger.Info("Caches are synced")
 
 	wg.Add(numWorkers)
 	for i := 0; i < numWorkers; i++ {
@@ -178,7 +182,7 @@ func (controller *backupController) processNextWorkItem() bool {
 		return true
 	}
 
-	glog.Errorf("syncHandler error: %v", err)
+	controller.logger.WithError(err).WithField("key", key).Error("Error in syncHandler, re-adding item to queue")
 	// we had an error processing the item so add it back
 	// into the queue for re-processing with rate-limiting
 	controller.queue.AddRateLimited(key)
@@ -187,18 +191,18 @@ func (controller *backupController) processNextWorkItem() bool {
 }
 
 func (controller *backupController) processBackup(key string) error {
-	glog.V(4).Infof("processBackup for key %q", key)
+	logContext := controller.logger.WithField("key", key)
+
+	logContext.Debug("Running processBackup")
 	ns, name, err := cache.SplitMetaNamespaceKey(key)
 	if err != nil {
-		glog.V(4).Infof("error splitting key %q: %v", key, err)
-		return err
+		return errors.Wrap(err, "error splitting queue key")
 	}
 
-	glog.V(4).Infof("Getting backup %s", key)
+	logContext.Debug("Getting backup")
 	backup, err := controller.lister.Backups(ns).Get(name)
 	if err != nil {
-		glog.V(4).Infof("error getting backup %s: %v", key, err)
-		return err
+		return errors.Wrap(err, "error getting backup")
 	}
 
 	// TODO I think this is now unnecessary. We only initially place
@@ -215,11 +219,10 @@ func (controller *backupController) processBackup(key string) error {
 		return nil
 	}
 
-	glog.V(4).Infof("Cloning backup %s", key)
+	logContext.Debug("Cloning backup")
 	// don't modify items in the cache
 	backup, err = cloneBackup(backup)
 	if err != nil {
-		glog.V(4).Infof("error cloning backup %s: %v", key, err)
 		return err
 	}
 
@@ -251,8 +254,7 @@ func (controller *backupController) processBackup(key string) error {
 	// update status
 	updatedBackup, err := controller.client.Backups(ns).Update(backup)
 	if err != nil {
-		glog.V(4).Infof("error updating status to %s: %v", backup.Status.Phase, err)
-		return err
+		return errors.Wrapf(err, "error updating Backup status to %s", backup.Status.Phase)
 	}
 	backup = updatedBackup
 
@@ -260,16 +262,16 @@ func (controller *backupController) processBackup(key string) error {
 		return nil
 	}
 
-	glog.V(4).Infof("running backup for %s", key)
+	logContext.Debug("Running backup")
 	// execution & upload of backup
 	if err := controller.runBackup(backup, controller.bucket); err != nil {
-		glog.V(4).Infof("backup %s failed: %v", key, err)
+		logContext.WithError(err).Error("backup failed")
 		backup.Status.Phase = api.BackupPhaseFailed
 	}
 
-	glog.V(4).Infof("updating backup %s final status", key)
+	logContext.Debug("Updating backup's final status")
 	if _, err = controller.client.Backups(ns).Update(backup); err != nil {
-		glog.V(4).Infof("error updating backup %s final status: %v", key, err)
+		logContext.WithError(err).Error("error updating backup's final status")
 	}
 
 	return nil
@@ -278,12 +280,12 @@ func (controller *backupController) processBackup(key string) error {
 func cloneBackup(in interface{}) (*api.Backup, error) {
 	clone, err := scheme.Scheme.DeepCopy(in)
 	if err != nil {
-		return nil, err
+		return nil, errors.Wrap(err, "error deep-copying Backup")
 	}
 
 	out, ok := clone.(*api.Backup)
 	if !ok {
-		return nil, fmt.Errorf("unexpected type: %T", clone)
+		return nil, errors.Errorf("unexpected type: %T", clone)
 	}
 
 	return out, nil
@@ -310,32 +312,33 @@ func (controller *backupController) getValidationErrors(itm *api.Backup) []strin
 func (controller *backupController) runBackup(backup *api.Backup, bucket string) error {
 	backupFile, err := ioutil.TempFile("", "")
 	if err != nil {
-		return err
+		return errors.Wrap(err, "error creating temp file for Backup")
 	}
 
 	logFile, err := ioutil.TempFile("", "")
 	if err != nil {
-		return err
+		return errors.Wrap(err, "error creating temp file for Backup log")
 	}
 
 	defer func() {
 		var errs []error
+		// TODO should this be wrapped?
 		errs = append(errs, err)
 
 		if err := backupFile.Close(); err != nil {
-			errs = append(errs, err)
+			errs = append(errs, errors.Wrap(err, "error closing Backup temp file"))
 		}
 
 		if err := os.Remove(backupFile.Name()); err != nil {
-			errs = append(errs, err)
+			errs = append(errs, errors.Wrap(err, "error removing Backup temp file"))
 		}
 
 		if err := logFile.Close(); err != nil {
-			errs = append(errs, err)
+			errs = append(errs, errors.Wrap(err, "error closing Backup log temp file"))
 		}
 
 		if err := os.Remove(logFile.Name()); err != nil {
-			errs = append(errs, err)
+			errs = append(errs, errors.Wrap(err, "error removing Backup log temp file"))
 		}
 
 		err = kuberrs.NewAggregate(errs)
@@ -344,23 +347,23 @@ func (controller *backupController) runBackup(backup *api.Backup, bucket string)
 	if err := controller.backupper.Backup(backup, backupFile, logFile); err != nil {
 		return err
 	}
+	controller.logger.WithField("backup", kubeutil.NamespaceAndName(backup)).Info("backup completed")
 
 	// note: updating this here so the uploaded JSON shows "completed". If
 	// the upload fails, we'll alter the phase in the calling func.
-	glog.V(4).Infof("backup %s/%s completed", backup.Namespace, backup.Name)
 	backup.Status.Phase = api.BackupPhaseCompleted
 
 	buf := new(bytes.Buffer)
 	if err := encode.EncodeTo(backup, "json", buf); err != nil {
-		return err
+		return errors.Wrap(err, "error encoding Backup")
 	}
 
 	// re-set the files' offset to 0 for reading
 	if _, err = backupFile.Seek(0, 0); err != nil {
-		return err
+		return errors.Wrap(err, "error resetting Backup file offset")
 	}
 	if _, err = logFile.Seek(0, 0); err != nil {
-		return err
+		return errors.Wrap(err, "error resetting Backup log file offset")
 	}
 
 	return controller.backupService.UploadBackup(bucket, backup.Name, bytes.NewReader(buf.Bytes()), backupFile, logFile)

pkg/controller/backup_controller_test.go

@@ -25,6 +25,7 @@ import (
 	"k8s.io/apimachinery/pkg/util/clock"
 	core "k8s.io/client-go/testing"
 
+	testlogger "github.com/sirupsen/logrus/hooks/test"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/mock"
 	"github.com/stretchr/testify/require"
@@ -146,18 +147,15 @@ func TestProcessBackup(t *testing.T) {
 		},
 	}
 
-	// flag.Set("logtostderr", "true")
-	// flag.Set("v", "4")
-
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			client := fake.NewSimpleClientset()
-
-			backupper := &fakeBackupper{}
-
-			cloudBackups := &BackupService{}
-
-			sharedInformers := informers.NewSharedInformerFactory(client, 0)
+			var (
+				client          = fake.NewSimpleClientset()
+				backupper       = &fakeBackupper{}
+				cloudBackups    = &BackupService{}
+				sharedInformers = informers.NewSharedInformerFactory(client, 0)
+				logger, _       = testlogger.NewNullLogger()
+			)
 
 			c := NewBackupController(
 				sharedInformers.Ark().V1().Backups(),
@@ -166,6 +164,7 @@ func TestProcessBackup(t *testing.T) {
 				cloudBackups,
 				"bucket",
 				test.allowSnapshots,
+				logger,
 			).(*backupController)
 			c.clock = clock.NewFakeClock(time.Now())
 

pkg/controller/backup_sync_controller.go

@@ -20,13 +20,15 @@ import (
 	"context"
 	"time"
 
-	"github.com/golang/glog"
+	"github.com/pkg/errors"
+	"github.com/sirupsen/logrus"
 
-	"k8s.io/apimachinery/pkg/api/errors"
+	kuberrs "k8s.io/apimachinery/pkg/api/errors"
 	"k8s.io/apimachinery/pkg/util/wait"
 
 	"github.com/heptio/ark/pkg/cloudprovider"
 	arkv1client "github.com/heptio/ark/pkg/generated/clientset/typed/ark/v1"
+	"github.com/heptio/ark/pkg/util/kube"
 )
 
 type backupSyncController struct {
@@ -34,11 +36,18 @@ type backupSyncController struct {
 	backupService cloudprovider.BackupService
 	bucket        string
 	syncPeriod    time.Duration
+	logger        *logrus.Logger
 }
 
-func NewBackupSyncController(client arkv1client.BackupsGetter, backupService cloudprovider.BackupService, bucket string, syncPeriod time.Duration) Interface {
+func NewBackupSyncController(
+	client arkv1client.BackupsGetter,
+	backupService cloudprovider.BackupService,
+	bucket string,
+	syncPeriod time.Duration,
+	logger *logrus.Logger,
+) Interface {
 	if syncPeriod < time.Minute {
-		glog.Infof("Backup sync period %v is too short. Setting to 1 minute", syncPeriod)
+		logger.Infof("Provided backup sync period %v is too short. Setting to 1 minute", syncPeriod)
 		syncPeriod = time.Minute
 	}
 	return &backupSyncController{
@@ -46,6 +55,7 @@ func NewBackupSyncController(client arkv1client.BackupsGetter, backupService clo
 		backupService: backupService,
 		bucket:        bucket,
 		syncPeriod:    syncPeriod,
+		logger:        logger,
 	}
 }
 
@@ -53,25 +63,27 @@ func NewBackupSyncController(client arkv1client.BackupsGetter, backupService clo
 // sync process according to the controller's syncPeriod. It will return when it
 // receives on the ctx.Done() channel.
 func (c *backupSyncController) Run(ctx context.Context, workers int) error {
-	glog.Info("Running backup sync controller")
+	c.logger.Info("Running backup sync controller")
 	wait.Until(c.run, c.syncPeriod, ctx.Done())
 	return nil
 }
 
 func (c *backupSyncController) run() {
-	glog.Info("Syncing backups from object storage")
+	c.logger.Info("Syncing backups from object storage")
 	backups, err := c.backupService.GetAllBackups(c.bucket)
 	if err != nil {
-		glog.Errorf("error listing backups: %v", err)
+		c.logger.WithError(err).Error("error listing backups")
 		return
 	}
-	glog.Infof("Found %d backups", len(backups))
+	c.logger.WithField("backupCount", len(backups)).Info("Got backups from object storage")
 
 	for _, cloudBackup := range backups {
-		glog.Infof("Syncing backup %s/%s", cloudBackup.Namespace, cloudBackup.Name)
+		logContext := c.logger.WithField("backup", kube.NamespaceAndName(cloudBackup))
+		logContext.Info("Syncing backup")
+
 		cloudBackup.ResourceVersion = ""
-		if _, err := c.client.Backups(cloudBackup.Namespace).Create(cloudBackup); err != nil && !errors.IsAlreadyExists(err) {
-			glog.Errorf("error syncing backup %s/%s from object storage: %v", cloudBackup.Namespace, cloudBackup.Name, err)
+		if _, err := c.client.Backups(cloudBackup.Namespace).Create(cloudBackup); err != nil && !kuberrs.IsAlreadyExists(err) {
+			logContext.WithError(errors.WithStack(err)).Error("Error syncing backup from object storage")
 		}
 	}
 }

pkg/controller/backup_sync_controller_test.go

@@ -21,6 +21,7 @@ import (
 	"testing"
 	"time"
 
+	testlogger "github.com/sirupsen/logrus/hooks/test"
 	"github.com/stretchr/testify/assert"
 
 	core "k8s.io/client-go/testing"
@@ -55,14 +56,18 @@ func TestBackupSyncControllerRun(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			bs := &BackupService{}
-			client := fake.NewSimpleClientset()
+			var (
+				bs        = &BackupService{}
+				client    = fake.NewSimpleClientset()
+				logger, _ = testlogger.NewNullLogger()
+			)
 
 			c := NewBackupSyncController(
 				client.ArkV1(),
 				bs,
 				"bucket",
 				time.Duration(0),
+				logger,
 			).(*backupSyncController)
 
 			bs.On("GetAllBackups", "bucket").Return(test.cloudBackups, test.getAllBackupsError)

pkg/controller/download_request_controller.go

@@ -18,18 +18,16 @@ package controller
 
 import (
 	"context"
-	"errors"
-	"fmt"
 	"sync"
 	"time"
 
-	"github.com/golang/glog"
+	"github.com/pkg/errors"
+	"github.com/sirupsen/logrus"
 
 	apierrors "k8s.io/apimachinery/pkg/api/errors"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"k8s.io/apimachinery/pkg/labels"
 	"k8s.io/apimachinery/pkg/util/clock"
-	"k8s.io/apimachinery/pkg/util/runtime"
 	"k8s.io/apimachinery/pkg/util/wait"
 	"k8s.io/client-go/tools/cache"
 	"k8s.io/client-go/util/workqueue"
@@ -40,20 +38,19 @@ import (
 	arkv1client "github.com/heptio/ark/pkg/generated/clientset/typed/ark/v1"
 	informers "github.com/heptio/ark/pkg/generated/informers/externalversions/ark/v1"
 	listers "github.com/heptio/ark/pkg/generated/listers/ark/v1"
+	"github.com/heptio/ark/pkg/util/kube"
 )
 
 type downloadRequestController struct {
 	downloadRequestClient       arkv1client.DownloadRequestsGetter
 	downloadRequestLister       listers.DownloadRequestLister
 	downloadRequestListerSynced cache.InformerSynced
-
-	backupService cloudprovider.BackupService
-	bucket        string
-
-	syncHandler func(key string) error
-	queue       workqueue.RateLimitingInterface
-
-	clock clock.Clock
+	backupService               cloudprovider.BackupService
+	bucket                      string
+	syncHandler                 func(key string) error
+	queue                       workqueue.RateLimitingInterface
+	clock                       clock.Clock
+	logger                      *logrus.Logger
 }
 
 // NewDownloadRequestController creates a new DownloadRequestController.
@@ -62,18 +59,17 @@ func NewDownloadRequestController(
 	downloadRequestInformer informers.DownloadRequestInformer,
 	backupService cloudprovider.BackupService,
 	bucket string,
+	logger *logrus.Logger,
 ) Interface {
 	c := &downloadRequestController{
 		downloadRequestClient:       downloadRequestClient,
 		downloadRequestLister:       downloadRequestInformer.Lister(),
 		downloadRequestListerSynced: downloadRequestInformer.Informer().HasSynced,
-
-		backupService: backupService,
-		bucket:        bucket,
-
-		queue: workqueue.NewNamedRateLimitingQueue(workqueue.DefaultControllerRateLimiter(), "downloadrequest"),
-
-		clock: &clock.RealClock{},
+		backupService:               backupService,
+		bucket:                      bucket,
+		queue:                       workqueue.NewNamedRateLimitingQueue(workqueue.DefaultControllerRateLimiter(), "downloadrequest"),
+		clock:                       &clock.RealClock{},
+		logger:                      logger,
 	}
 
 	c.syncHandler = c.processDownloadRequest
@@ -83,7 +79,10 @@ func NewDownloadRequestController(
 			AddFunc: func(obj interface{}) {
 				key, err := cache.MetaNamespaceKeyFunc(obj)
 				if err != nil {
-					runtime.HandleError(fmt.Errorf("error creating queue key for %#v: %v", obj, err))
+					downloadRequest := obj.(*v1.DownloadRequest)
+					c.logger.WithError(errors.WithStack(err)).
+						WithField("downloadRequest", downloadRequest.Name).
+						Error("Error creating queue key, item not added to queue")
 					return
 				}
 				c.queue.Add(key)
@@ -101,7 +100,7 @@ func (c *downloadRequestController) Run(ctx context.Context, numWorkers int) err
 	var wg sync.WaitGroup
 
 	defer func() {
-		glog.Infof("Waiting for workers to finish their work")
+		c.logger.Info("Waiting for workers to finish their work")
 
 		c.queue.ShutDown()
 
@@ -110,17 +109,17 @@ func (c *downloadRequestController) Run(ctx context.Context, numWorkers int) err
 		// we want to shut down the queue via defer and not at the end of the body.
 		wg.Wait()
 
-		glog.Infof("All workers have finished")
+		c.logger.Info("All workers have finished")
 	}()
 
-	glog.Info("Starting DownloadRequestController")
-	defer glog.Infof("Shutting down DownloadRequestController")
+	c.logger.Info("Starting DownloadRequestController")
+	defer c.logger.Info("Shutting down DownloadRequestController")
 
-	glog.Info("Waiting for caches to sync")
+	c.logger.Info("Waiting for caches to sync")
 	if !cache.WaitForCacheSync(ctx.Done(), c.downloadRequestListerSynced) {
 		return errors.New("timed out waiting for caches to sync")
 	}
-	glog.Info("Caches are synced")
+	c.logger.Info("Caches are synced")
 
 	wg.Add(numWorkers)
 	for i := 0; i < numWorkers; i++ {
@@ -167,7 +166,8 @@ func (c *downloadRequestController) processNextWorkItem() bool {
 		return true
 	}
 
-	glog.Errorf("syncHandler error: %v", err)
+	c.logger.WithError(err).WithField("key", key).Error("Error in syncHandler, re-adding item to queue")
+
 	// we had an error processing the item so add it back
 	// into the queue for re-processing with rate-limiting
 	c.queue.AddRateLimited(key)
@@ -178,21 +178,21 @@ func (c *downloadRequestController) processNextWorkItem() bool {
 // processDownloadRequest is the default per-item sync handler. It generates a pre-signed URL for
 // a new DownloadRequest or deletes the DownloadRequest if it has expired.
 func (c *downloadRequestController) processDownloadRequest(key string) error {
-	glog.V(4).Infof("processDownloadRequest for key %q", key)
+	logContext := c.logger.WithField("key", key)
+
+	logContext.Debug("Running processDownloadRequest")
 	ns, name, err := cache.SplitMetaNamespaceKey(key)
 	if err != nil {
-		glog.V(4).Infof("error splitting key %q: %v", key, err)
-		return err
+		return errors.Wrap(err, "error splitting queue key")
 	}
 
 	downloadRequest, err := c.downloadRequestLister.DownloadRequests(ns).Get(name)
 	if apierrors.IsNotFound(err) {
-		glog.V(4).Infof("unable to find DownloadRequest %q", key)
+		logContext.Debug("Unable to find DownloadRequest")
 		return nil
 	}
 	if err != nil {
-		glog.V(4).Infof("error getting DownloadRequest %q: %v", key, err)
-		return err
+		return errors.Wrap(err, "error getting DownloadRequest")
 	}
 
 	switch downloadRequest.Status.Phase {
@@ -224,20 +224,20 @@ func (c *downloadRequestController) generatePreSignedURL(downloadRequest *v1.Dow
 	update.Status.Expiration = metav1.NewTime(c.clock.Now().Add(signedURLTTL))
 
 	_, err = c.downloadRequestClient.DownloadRequests(update.Namespace).Update(update)
-	return err
-
+	return errors.WithStack(err)
 }
 
 // deleteIfExpired deletes downloadRequest if it has expired.
 func (c *downloadRequestController) deleteIfExpired(downloadRequest *v1.DownloadRequest) error {
-	glog.V(4).Infof("checking for expiration of %s/%s", downloadRequest.Namespace, downloadRequest.Name)
+	logContext := c.logger.WithField("key", kube.NamespaceAndName(downloadRequest))
+	logContext.Info("checking for expiration of DownloadRequest")
 	if downloadRequest.Status.Expiration.Time.Before(c.clock.Now()) {
-		glog.V(4).Infof("%s/%s has not expired", downloadRequest.Namespace, downloadRequest.Name)
+		logContext.Debug("DownloadRequest has not expired")
 		return nil
 	}
 
-	glog.V(4).Infof("%s/%s has expired - deleting", downloadRequest.Namespace, downloadRequest.Name)
-	return c.downloadRequestClient.DownloadRequests(downloadRequest.Namespace).Delete(downloadRequest.Name, nil)
+	logContext.Debug("DownloadRequest has expired - deleting")
+	return errors.WithStack(c.downloadRequestClient.DownloadRequests(downloadRequest.Namespace).Delete(downloadRequest.Name, nil))
 }
 
 // resync requeues all the DownloadRequests in the lister's cache. This is mostly to handle deleting
@@ -245,14 +245,14 @@ func (c *downloadRequestController) deleteIfExpired(downloadRequest *v1.Download
 func (c *downloadRequestController) resync() {
 	list, err := c.downloadRequestLister.List(labels.Everything())
 	if err != nil {
-		runtime.HandleError(fmt.Errorf("error listing download requests: %v", err))
+		c.logger.WithError(errors.WithStack(err)).Error("error listing download requests")
 		return
 	}
 
 	for _, dr := range list {
 		key, err := cache.MetaNamespaceKeyFunc(dr)
 		if err != nil {
-			runtime.HandleError(fmt.Errorf("error generating key for download request %#v: %v", dr, err))
+			c.logger.WithError(errors.WithStack(err)).WithField("downloadRequest", dr.Name).Error("error generating key for download request")
 			continue
 		}
 
@@ -264,12 +264,12 @@ func (c *downloadRequestController) resync() {
 func cloneDownloadRequest(in *v1.DownloadRequest) (*v1.DownloadRequest, error) {
 	clone, err := scheme.Scheme.DeepCopy(in)
 	if err != nil {
-		return nil, err
+		return nil, errors.Wrap(err, "error deep-copying DownloadRequest")
 	}
 
 	out, ok := clone.(*v1.DownloadRequest)
 	if !ok {
-		return nil, fmt.Errorf("unexpected type: %T", clone)
+		return nil, errors.Errorf("unexpected type: %T", clone)
 	}
 
 	return out, nil

pkg/controller/download_request_controller_test.go

@@ -20,6 +20,10 @@ import (
 	"testing"
 	"time"
 
+	testlogger "github.com/sirupsen/logrus/hooks/test"
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"k8s.io/apimachinery/pkg/runtime"
 	core "k8s.io/client-go/testing"
@@ -28,8 +32,6 @@ import (
 	"github.com/heptio/ark/pkg/generated/clientset/fake"
 	informers "github.com/heptio/ark/pkg/generated/informers/externalversions"
 	"github.com/heptio/ark/pkg/util/test"
-	"github.com/stretchr/testify/assert"
-	"github.com/stretchr/testify/require"
 )
 
 func TestProcessDownloadRequest(t *testing.T) {
@@ -50,7 +52,7 @@ func TestProcessDownloadRequest(t *testing.T) {
 		{
 			name:          "bad key format",
 			key:           "a/b/c",
-			expectedError: `unexpected key format: "a/b/c"`,
+			expectedError: `error splitting queue key: unexpected key format: "a/b/c"`,
 		},
 		{
 			name:          "backup log request with phase '' gets a url",
@@ -92,10 +94,13 @@ func TestProcessDownloadRequest(t *testing.T) {
 
 	for _, tc := range tests {
 		t.Run(tc.name, func(t *testing.T) {
-			client := fake.NewSimpleClientset()
-			sharedInformers := informers.NewSharedInformerFactory(client, 0)
-			downloadRequestsInformer := sharedInformers.Ark().V1().DownloadRequests()
-			backupService := &test.BackupService{}
+			var (
+				client                   = fake.NewSimpleClientset()
+				sharedInformers          = informers.NewSharedInformerFactory(client, 0)
+				downloadRequestsInformer = sharedInformers.Ark().V1().DownloadRequests()
+				backupService            = &test.BackupService{}
+				logger, _                = testlogger.NewNullLogger()
+			)
 			defer backupService.AssertExpectations(t)
 
 			c := NewDownloadRequestController(
@@ -103,6 +108,7 @@ func TestProcessDownloadRequest(t *testing.T) {
 				downloadRequestsInformer,
 				backupService,
 				"bucket",
+				logger,
 			).(*downloadRequestController)
 
 			if tc.expectedPhase == v1.DownloadRequestPhaseProcessed {

pkg/controller/gc_controller.go

@@ -18,10 +18,10 @@ package controller
 
 import (
 	"context"
-	"errors"
 	"time"
 
-	"github.com/golang/glog"
+	"github.com/pkg/errors"
+	"github.com/sirupsen/logrus"
 
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"k8s.io/apimachinery/pkg/labels"
@@ -50,6 +50,7 @@ type gcController struct {
 	restoreLister       listers.RestoreLister
 	restoreListerSynced cache.InformerSynced
 	restoreClient       arkv1client.RestoresGetter
+	logger              *logrus.Logger
 }
 
 // NewGCController constructs a new gcController.
@@ -62,9 +63,10 @@ func NewGCController(
 	backupClient arkv1client.BackupsGetter,
 	restoreInformer informers.RestoreInformer,
 	restoreClient arkv1client.RestoresGetter,
+	logger *logrus.Logger,
 ) Interface {
 	if syncPeriod < time.Minute {
-		glog.Infof("GC sync period %v is too short. Setting to 1 minute", syncPeriod)
+		logger.WithField("syncPeriod", syncPeriod).Info("Provided GC sync period is too short. Setting to 1 minute")
 		syncPeriod = time.Minute
 	}
 
@@ -80,6 +82,7 @@ func NewGCController(
 		restoreLister:       restoreInformer.Lister(),
 		restoreListerSynced: restoreInformer.Informer().HasSynced,
 		restoreClient:       restoreClient,
+		logger:              logger,
 	}
 }
 
@@ -89,11 +92,11 @@ var _ Interface = &gcController{}
 // from object/block storage and the Ark API. It will return when it receives on the
 // ctx.Done() channel.
 func (c *gcController) Run(ctx context.Context, workers int) error {
-	glog.Info("Waiting for caches to sync")
+	c.logger.Info("Waiting for caches to sync")
 	if !cache.WaitForCacheSync(ctx.Done(), c.backupListerSynced, c.restoreListerSynced) {
 		return errors.New("timed out waiting for caches to sync")
 	}
-	glog.Info("Caches are synced")
+	c.logger.Info("Caches are synced")
 
 	wait.Until(c.run, c.syncPeriod, ctx.Done())
 	return nil
@@ -107,11 +110,12 @@ func (c *gcController) run() {
 // deleteBackupFiles = true), volume snapshots, restore API objects, and the backup API object
 // itself.
 func (c *gcController) garbageCollectBackup(backup *api.Backup, deleteBackupFiles bool) {
+	logContext := c.logger.WithField("backup", kube.NamespaceAndName(backup))
+
 	// if the backup includes snapshots but we don't currently have a PVProvider, we don't
 	// want to orphan the snapshots so skip garbage-collection entirely.
 	if c.snapshotService == nil && len(backup.Status.VolumeBackups) > 0 {
-		glog.Warningf("Cannot garbage-collect backup %s because backup includes snapshots and server is not configured with PersistentVolumeProvider",
-			kube.NamespaceAndName(backup))
+		logContext.Warning("Cannot garbage-collect backup because backup includes snapshots and server is not configured with PersistentVolumeProvider")
 		return
 	}
 
@@ -121,9 +125,9 @@ func (c *gcController) garbageCollectBackup(backup *api.Backup, deleteBackupFile
 	deletionFailure := false
 
 	for _, volumeBackup := range backup.Status.VolumeBackups {
-		glog.Infof("Removing snapshot %s associated with backup %s", volumeBackup.SnapshotID, kube.NamespaceAndName(backup))
+		logContext.WithField("snapshotID", volumeBackup.SnapshotID).Info("Removing snapshot associated with backup")
 		if err := c.snapshotService.DeleteSnapshot(volumeBackup.SnapshotID); err != nil {
-			glog.Errorf("error deleting snapshot %v: %v", volumeBackup.SnapshotID, err)
+			logContext.WithError(err).WithField("snapshotID", volumeBackup.SnapshotID).Error("Error deleting snapshot")
 			deletionFailure = true
 		}
 	}
@@ -131,35 +135,36 @@ func (c *gcController) garbageCollectBackup(backup *api.Backup, deleteBackupFile
 	// If applicable, delete everything in the backup dir in object storage *before* deleting the API object
 	// because otherwise the backup sync controller could re-sync the backup from object storage.
 	if deleteBackupFiles {
-		glog.Infof("Removing backup %s from object storage", kube.NamespaceAndName(backup))
+		logContext.Info("Removing backup from object storage")
 		if err := c.backupService.DeleteBackupDir(c.bucket, backup.Name); err != nil {
-			glog.Errorf("error deleting backup %s: %v", kube.NamespaceAndName(backup), err)
+			logContext.WithError(err).Error("Error deleting backup")
 			deletionFailure = true
 		}
 	}
 
-	glog.Infof("Getting restore API objects referencing backup %s", kube.NamespaceAndName(backup))
+	logContext.Info("Getting restore API objects referencing backup")
 	if restores, err := c.restoreLister.Restores(backup.Namespace).List(labels.Everything()); err != nil {
-		glog.Errorf("error getting restore API objects: %v", err)
+		logContext.WithError(errors.WithStack(err)).Error("Error getting Restore API objects")
 	} else {
 		for _, restore := range restores {
 			if restore.Spec.BackupName == backup.Name {
-				glog.Infof("Removing restore API object %s of backup %s", kube.NamespaceAndName(restore), kube.NamespaceAndName(backup))
+				logContext.WithField("restore", kube.NamespaceAndName(restore)).Info("Removing Restore API object referencing Backup")
 				if err := c.restoreClient.Restores(restore.Namespace).Delete(restore.Name, &metav1.DeleteOptions{}); err != nil {
-					glog.Errorf("error deleting restore API object %s: %v", kube.NamespaceAndName(restore), err)
+					logContext.WithError(errors.WithStack(err)).WithField("restore", kube.NamespaceAndName(restore)).
+						Error("Error deleting Restore API object")
 				}
 			}
 		}
 	}
 
 	if deletionFailure {
-		glog.Warningf("Backup %s will not be deleted due to errors deleting related object storage files(s) and/or volume snapshots", kube.NamespaceAndName(backup))
+		logContext.Warning("Backup will not be deleted due to errors deleting related object storage files(s) and/or volume snapshots")
 		return
 	}
 
-	glog.Infof("Removing backup API object %s", kube.NamespaceAndName(backup))
+	logContext.Info("Removing Backup API object")
 	if err := c.backupClient.Backups(backup.Namespace).Delete(backup.Name, &metav1.DeleteOptions{}); err != nil {
-		glog.Errorf("error deleting backup API object %s: %v", kube.NamespaceAndName(backup), err)
+		logContext.WithError(errors.WithStack(err)).Error("Error deleting Backup API object")
 	}
 }
 
@@ -168,7 +173,7 @@ func (c *gcController) garbageCollectBackup(backup *api.Backup, deleteBackupFile
 func (c *gcController) garbageCollectBackups(backups []*api.Backup, expiration time.Time, deleteBackupFiles bool) {
 	for _, backup := range backups {
 		if backup.Status.Expiration.Time.After(expiration) {
-			glog.Infof("Backup %s has not expired yet, skipping", kube.NamespaceAndName(backup))
+			c.logger.WithField("backup", kube.NamespaceAndName(backup)).Info("Backup has not expired yet, skipping")
 			continue
 		}
 
@@ -180,13 +185,13 @@ func (c *gcController) garbageCollectBackups(backups []*api.Backup, expiration t
 // them for garbage-collection.
 func (c *gcController) processBackups() {
 	now := c.clock.Now()
-	glog.Infof("garbage-collecting backups that have expired as of %v", now)
+	c.logger.WithField("now", now).Info("Garbage-collecting backups that have expired as of now")
 
 	// GC backups in object storage. We do this in addition
 	// to GC'ing API objects to prevent orphan backup files.
 	backups, err := c.backupService.GetAllBackups(c.bucket)
 	if err != nil {
-		glog.Errorf("error getting all backups from object storage: %v", err)
+		c.logger.WithError(err).Error("Error getting all backups from object storage")
 		return
 	}
 	c.garbageCollectBackups(backups, now, true)
@@ -194,7 +199,7 @@ func (c *gcController) processBackups() {
 	// GC backups without files in object storage
 	apiBackups, err := c.backupLister.List(labels.Everything())
 	if err != nil {
-		glog.Errorf("error getting all backup API objects: %v", err)
+		c.logger.WithError(errors.WithStack(err)).Error("Error getting all Backup API objects")
 		return
 	}
 	c.garbageCollectBackups(apiBackups, now, false)

pkg/controller/gc_controller_test.go

@@ -20,6 +20,7 @@ import (
 	"testing"
 	"time"
 
+	testlogger "github.com/sirupsen/logrus/hooks/test"
 	"github.com/stretchr/testify/assert"
 
 	"k8s.io/apimachinery/pkg/util/clock"
@@ -151,6 +152,7 @@ func TestGarbageCollect(t *testing.T) {
 				sharedInformers = informers.NewSharedInformerFactory(client, 0)
 				snapSvc         cloudprovider.SnapshotService
 				bucket          = "bucket"
+				logger, _       = testlogger.NewNullLogger()
 			)
 
 			if snapshotService != nil {
@@ -166,6 +168,7 @@ func TestGarbageCollect(t *testing.T) {
 				client.ArkV1(),
 				sharedInformers.Ark().V1().Restores(),
 				client.ArkV1(),
+				logger,
 			).(*gcController)
 			controller.clock = fakeClock
 
@@ -234,6 +237,7 @@ func TestGarbageCollectBackup(t *testing.T) {
 				client          = fake.NewSimpleClientset()
 				sharedInformers = informers.NewSharedInformerFactory(client, 0)
 				bucket          = "bucket-1"
+				logger, _       = testlogger.NewNullLogger()
 				controller      = NewGCController(
 					backupService,
 					snapshotService,
@@ -243,6 +247,7 @@ func TestGarbageCollectBackup(t *testing.T) {
 					client.ArkV1(),
 					sharedInformers.Ark().V1().Restores(),
 					client.ArkV1(),
+					logger,
 				).(*gcController)
 			)
 
@@ -316,6 +321,7 @@ func TestGarbageCollectPicksUpBackupUponExpiration(t *testing.T) {
 	var (
 		client          = fake.NewSimpleClientset()
 		sharedInformers = informers.NewSharedInformerFactory(client, 0)
+		logger, _       = testlogger.NewNullLogger()
 	)
 
 	controller := NewGCController(
@@ -327,6 +333,7 @@ func TestGarbageCollectPicksUpBackupUponExpiration(t *testing.T) {
 		client.ArkV1(),
 		sharedInformers.Ark().V1().Restores(),
 		client.ArkV1(),
+		logger,
 	).(*gcController)
 	controller.clock = fakeClock
 

pkg/controller/restore_controller.go

@@ -18,7 +18,6 @@ package controller
 
 import (
 	"context"
-	"errors"
 	"fmt"
 	"io"
 	"io/ioutil"
@@ -26,7 +25,8 @@ import (
 	"sync"
 	"time"
 
-	"github.com/golang/glog"
+	"github.com/pkg/errors"
+	"github.com/sirupsen/logrus"
 
 	apierrors "k8s.io/apimachinery/pkg/api/errors"
 	"k8s.io/apimachinery/pkg/util/wait"
@@ -41,22 +41,23 @@ import (
 	listers "github.com/heptio/ark/pkg/generated/listers/ark/v1"
 	"github.com/heptio/ark/pkg/restore"
 	"github.com/heptio/ark/pkg/util/collections"
+	kubeutil "github.com/heptio/ark/pkg/util/kube"
 )
 
 type restoreController struct {
-	restoreClient    arkv1client.RestoresGetter
-	backupClient     arkv1client.BackupsGetter
-	restorer         restore.Restorer
-	backupService    cloudprovider.BackupService
-	bucket           string
-	pvProviderExists bool
-
+	restoreClient       arkv1client.RestoresGetter
+	backupClient        arkv1client.BackupsGetter
+	restorer            restore.Restorer
+	backupService       cloudprovider.BackupService
+	bucket              string
+	pvProviderExists    bool
 	backupLister        listers.BackupLister
 	backupListerSynced  cache.InformerSynced
 	restoreLister       listers.RestoreLister
 	restoreListerSynced cache.InformerSynced
 	syncHandler         func(restoreName string) error
 	queue               workqueue.RateLimitingInterface
+	logger              *logrus.Logger
 }
 
 func NewRestoreController(
@@ -68,6 +69,7 @@ func NewRestoreController(
 	bucket string,
 	backupInformer informers.BackupInformer,
 	pvProviderExists bool,
+	logger *logrus.Logger,
 ) Interface {
 	c := &restoreController{
 		restoreClient:       restoreClient,
@@ -81,6 +83,7 @@ func NewRestoreController(
 		restoreLister:       restoreInformer.Lister(),
 		restoreListerSynced: restoreInformer.Informer().HasSynced,
 		queue:               workqueue.NewNamedRateLimitingQueue(workqueue.DefaultControllerRateLimiter(), "restore"),
+		logger:              logger,
 	}
 
 	c.syncHandler = c.processRestore
@@ -94,13 +97,16 @@ func NewRestoreController(
 				case "", api.RestorePhaseNew:
 					// only process new restores
 				default:
-					glog.V(4).Infof("Restore %s/%s has phase %s - skipping", restore.Namespace, restore.Name, restore.Status.Phase)
+					c.logger.WithFields(logrus.Fields{
+						"restore": kubeutil.NamespaceAndName(restore),
+						"phase":   restore.Status.Phase,
+					}).Debug("Restore is not new, skipping")
 					return
 				}
 
 				key, err := cache.MetaNamespaceKeyFunc(restore)
 				if err != nil {
-					glog.Errorf("error creating queue key for %#v: %v", restore, err)
+					c.logger.WithError(errors.WithStack(err)).WithField("restore", restore).Error("Error creating queue key, item not added to queue")
 					return
 				}
 				c.queue.Add(key)
@@ -118,7 +124,7 @@ func (controller *restoreController) Run(ctx context.Context, numWorkers int) er
 	var wg sync.WaitGroup
 
 	defer func() {
-		glog.Infof("Waiting for workers to finish their work")
+		controller.logger.Info("Waiting for workers to finish their work")
 
 		controller.queue.ShutDown()
 
@@ -127,17 +133,17 @@ func (controller *restoreController) Run(ctx context.Context, numWorkers int) er
 		// we want to shut down the queue via defer and not at the end of the body.
 		wg.Wait()
 
-		glog.Infof("All workers have finished")
+		controller.logger.Info("All workers have finished")
 	}()
 
-	glog.Info("Starting RestoreController")
-	defer glog.Info("Shutting down RestoreController")
+	controller.logger.Info("Starting RestoreController")
+	defer controller.logger.Info("Shutting down RestoreController")
 
-	glog.Info("Waiting for caches to sync")
+	controller.logger.Info("Waiting for caches to sync")
 	if !cache.WaitForCacheSync(ctx.Done(), controller.backupListerSynced, controller.restoreListerSynced) {
 		return errors.New("timed out waiting for caches to sync")
 	}
-	glog.Info("Caches are synced")
+	controller.logger.Info("Caches are synced")
 
 	wg.Add(numWorkers)
 	for i := 0; i < numWorkers; i++ {
@@ -176,7 +182,7 @@ func (controller *restoreController) processNextWorkItem() bool {
 		return true
 	}
 
-	glog.Errorf("syncHandler error: %v", err)
+	controller.logger.WithError(err).WithField("key", key).Error("Error in syncHandler, re-adding item to queue")
 	// we had an error processing the item so add it back
 	// into the queue for re-processing with rate-limiting
 	controller.queue.AddRateLimited(key)
@@ -185,18 +191,18 @@ func (controller *restoreController) processNextWorkItem() bool {
 }
 
 func (controller *restoreController) processRestore(key string) error {
-	glog.V(4).Infof("processRestore for key %q", key)
+	logContext := controller.logger.WithField("key", key)
+
+	logContext.Debug("Running processRestore")
 	ns, name, err := cache.SplitMetaNamespaceKey(key)
 	if err != nil {
-		glog.V(4).Infof("error splitting key %q: %v", key, err)
-		return err
+		return errors.Wrap(err, "error splitting queue key")
 	}
 
-	glog.V(4).Infof("Getting restore %s", key)
+	logContext.Debug("Getting Restore")
 	restore, err := controller.restoreLister.Restores(ns).Get(name)
 	if err != nil {
-		glog.V(4).Infof("error getting restore %s: %v", key, err)
-		return err
+		return errors.Wrap(err, "error getting Restore")
 	}
 
 	// TODO I think this is now unnecessary. We only initially place
@@ -213,11 +219,10 @@ func (controller *restoreController) processRestore(key string) error {
 		return nil
 	}
 
-	glog.V(4).Infof("Cloning restore %s", key)
+	logContext.Debug("Cloning Restore")
 	// don't modify items in the cache
 	restore, err = cloneRestore(restore)
 	if err != nil {
-		glog.V(4).Infof("error cloning restore %s: %v", key, err)
 		return err
 	}
 
@@ -239,8 +244,7 @@ func (controller *restoreController) processRestore(key string) error {
 	// update status
 	updatedRestore, err := controller.restoreClient.Restores(ns).Update(restore)
 	if err != nil {
-		glog.V(4).Infof("error updating status to %s: %v", restore.Status.Phase, err)
-		return err
+		return errors.Wrapf(err, "error updating Restore phase to %s", restore.Status.Phase)
 	}
 	restore = updatedRestore
 
@@ -248,16 +252,16 @@ func (controller *restoreController) processRestore(key string) error {
 		return nil
 	}
 
-	glog.V(4).Infof("running restore for %s", key)
+	logContext.Debug("Running restore")
 	// execution & upload of restore
 	restore.Status.Warnings, restore.Status.Errors = controller.runRestore(restore, controller.bucket)
 
-	glog.V(4).Infof("restore %s completed", key)
+	logContext.Debug("restore completed")
 	restore.Status.Phase = api.RestorePhaseCompleted
 
-	glog.V(4).Infof("updating restore %s final status", key)
+	logContext.Debug("Updating Restore final status")
 	if _, err = controller.restoreClient.Restores(ns).Update(restore); err != nil {
-		glog.V(4).Infof("error updating restore %s final status: %v", key, err)
+		logContext.WithError(errors.WithStack(err)).Info("Error updating Restore final status")
 	}
 
 	return nil
@@ -266,12 +270,12 @@ func (controller *restoreController) processRestore(key string) error {
 func cloneRestore(in interface{}) (*api.Restore, error) {
 	clone, err := scheme.Scheme.DeepCopy(in)
 	if err != nil {
-		return nil, err
+		return nil, errors.Wrap(err, "error deep-copying Restore")
 	}
 
 	out, ok := clone.(*api.Restore)
 	if !ok {
-		return nil, fmt.Errorf("unexpected type: %T", clone)
+		return nil, errors.Errorf("unexpected type: %T", clone)
 	}
 
 	return out, nil
@@ -306,13 +310,14 @@ func (controller *restoreController) fetchBackup(bucket, name string) (*api.Back
 	}
 
 	if !apierrors.IsNotFound(err) {
-		return nil, err
+		return nil, errors.WithStack(err)
 	}
 
-	glog.V(4).Infof("Backup %q not found in backupLister, checking object storage directly.", name)
+	logContext := controller.logger.WithField("backupName", name)
+
+	logContext.Debug("Backup not found in backupLister, checking object storage directly")
 	backup, err = controller.backupService.GetBackup(bucket, name)
 	if err != nil {
-		glog.V(4).Infof("Backup %q not found in object storage.", name)
 		return nil, err
 	}
 
@@ -321,7 +326,7 @@ func (controller *restoreController) fetchBackup(bucket, name string) (*api.Back
 
 	created, createErr := controller.backupClient.Backups(api.DefaultNamespace).Create(backup)
 	if createErr != nil {
-		glog.Errorf("Unable to create API object for backup %q: %v", name, createErr)
+		logContext.WithError(errors.WithStack(createErr)).Error("Unable to create API object for Backup")
 	} else {
 		backup = created
 	}
@@ -329,64 +334,66 @@ func (controller *restoreController) fetchBackup(bucket, name string) (*api.Back
 	return backup, nil
 }
 
-func (controller *restoreController) runRestore(restore *api.Restore, bucket string) (warnings, errors api.RestoreResult) {
+func (controller *restoreController) runRestore(restore *api.Restore, bucket string) (warnings, restoreErrors api.RestoreResult) {
+	logContext := controller.logger.WithField("restore", kubeutil.NamespaceAndName(restore))
+
 	backup, err := controller.fetchBackup(bucket, restore.Spec.BackupName)
 	if err != nil {
-		glog.Errorf("error getting backup: %v", err)
-		errors.Ark = append(errors.Ark, err.Error())
+		logContext.WithError(err).WithField("backup", restore.Spec.BackupName).Error("Error getting backup")
+		restoreErrors.Ark = append(restoreErrors.Ark, err.Error())
 		return
 	}
 
-	tmpFile, err := downloadToTempFile(restore.Spec.BackupName, controller.backupService, bucket)
+	tmpFile, err := downloadToTempFile(restore.Spec.BackupName, controller.backupService, bucket, controller.logger)
 	if err != nil {
-		glog.Errorf("error downloading backup: %v", err)
-		errors.Ark = append(errors.Ark, err.Error())
+		logContext.WithError(err).WithField("backup", restore.Spec.BackupName).Error("Error downloading backup")
+		restoreErrors.Ark = append(restoreErrors.Ark, err.Error())
 		return
 	}
 
 	logFile, err := ioutil.TempFile("", "")
 	if err != nil {
-		glog.Errorf("error creating log temp file: %v", err)
-		errors.Ark = append(errors.Ark, err.Error())
+		logContext.WithError(errors.WithStack(err)).Error("Error creating log temp file")
+		restoreErrors.Ark = append(restoreErrors.Ark, err.Error())
 		return
 	}
 
 	defer func() {
 		if err := tmpFile.Close(); err != nil {
-			glog.Errorf("error closing %q: %v", tmpFile.Name(), err)
+			logContext.WithError(errors.WithStack(err)).WithField("file", tmpFile.Name()).Error("Error closing file")
 		}
 
 		if err := os.Remove(tmpFile.Name()); err != nil {
-			glog.Errorf("error removing %q: %v", tmpFile.Name(), err)
+			logContext.WithError(errors.WithStack(err)).WithField("file", tmpFile.Name()).Error("Error removing file")
 		}
 
 		if err := logFile.Close(); err != nil {
-			glog.Errorf("error closing %q: %v", logFile.Name(), err)
+			logContext.WithError(errors.WithStack(err)).WithField("file", logFile.Name()).Error("Error closing file")
 		}
 
 		if err := os.Remove(logFile.Name()); err != nil {
-			glog.Errorf("error removing %q: %v", logFile.Name(), err)
+			logContext.WithError(errors.WithStack(err)).WithField("file", logFile.Name()).Error("Error removing file")
 		}
 	}()
 
-	warnings, errors = controller.restorer.Restore(restore, backup, tmpFile, logFile)
+	warnings, restoreErrors = controller.restorer.Restore(restore, backup, tmpFile, logFile)
 
 	// Try to upload the log file. This is best-effort. If we fail, we'll add to the ark errors.
 
 	// Reset the offset to 0 for reading
 	if _, err = logFile.Seek(0, 0); err != nil {
-		errors.Ark = append(errors.Ark, fmt.Sprintf("error resetting log file offset to 0: %v", err))
+		restoreErrors.Ark = append(restoreErrors.Ark, fmt.Sprintf("error resetting log file offset to 0: %v", err))
 		return
 	}
 
 	if err := controller.backupService.UploadRestoreLog(bucket, restore.Spec.BackupName, restore.Name, logFile); err != nil {
-		errors.Ark = append(errors.Ark, fmt.Sprintf("error uploading log file to object storage: %v", err))
+		restoreErrors.Ark = append(restoreErrors.Ark, fmt.Sprintf("error uploading log file to object storage: %v", err))
 	}
 
 	return
 }
 
-func downloadToTempFile(backupName string, backupService cloudprovider.BackupService, bucket string) (*os.File, error) {
+func downloadToTempFile(backupName string, backupService cloudprovider.BackupService, bucket string, logger *logrus.Logger) (*os.File, error) {
 	readCloser, err := backupService.DownloadBackup(bucket, backupName)
 	if err != nil {
 		return nil, err
@@ -395,18 +402,23 @@ func downloadToTempFile(backupName string, backupService cloudprovider.BackupSer
 
 	file, err := ioutil.TempFile("", backupName)
 	if err != nil {
-		return nil, err
+		return nil, errors.Wrap(err, "error creating Backup temp file")
 	}
 
 	n, err := io.Copy(file, readCloser)
 	if err != nil {
-		return nil, err
+		return nil, errors.Wrap(err, "error copying Backup to temp file")
 	}
-	glog.V(4).Infof("copied %d bytes", n)
+
+	logContext := logger.WithField("backup", backupName)
+
+	logContext.WithFields(logrus.Fields{
+		"fileName": file.Name(),
+		"bytes":    n,
+	}).Debug("Copied Backup to file")
 
 	if _, err := file.Seek(0, 0); err != nil {
-		glog.V(4).Infof("error seeking: %v", err)
-		return nil, err
+		return nil, errors.Wrap(err, "error resetting Backup file offset")
 	}
 
 	return file, nil

pkg/controller/restore_controller_test.go

@@ -23,6 +23,7 @@ import (
 	"io/ioutil"
 	"testing"
 
+	testlogger "github.com/sirupsen/logrus/hooks/test"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/mock"
 
@@ -74,6 +75,7 @@ func TestFetchBackup(t *testing.T) {
 				restorer        = &fakeRestorer{}
 				sharedInformers = informers.NewSharedInformerFactory(client, 0)
 				backupSvc       = &BackupService{}
+				logger, _       = testlogger.NewNullLogger()
 			)
 
 			c := NewRestoreController(
@@ -85,6 +87,7 @@ func TestFetchBackup(t *testing.T) {
 				"bucket",
 				sharedInformers.Ark().V1().Backups(),
 				false,
+				logger,
 			).(*restoreController)
 
 			for _, itm := range test.informerBackups {
@@ -260,14 +263,15 @@ func TestProcessRestore(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			client := fake.NewSimpleClientset()
+			var (
+				client          = fake.NewSimpleClientset()
+				restorer        = &fakeRestorer{}
+				sharedInformers = informers.NewSharedInformerFactory(client, 0)
+				backupSvc       = &BackupService{}
+				logger, _       = testlogger.NewNullLogger()
+			)
 
-			restorer := &fakeRestorer{}
 			defer restorer.AssertExpectations(t)
-
-			sharedInformers := informers.NewSharedInformerFactory(client, 0)
-
-			backupSvc := &BackupService{}
 			defer backupSvc.AssertExpectations(t)
 
 			c := NewRestoreController(
@@ -279,6 +283,7 @@ func TestProcessRestore(t *testing.T) {
 				"bucket",
 				sharedInformers.Ark().V1().Backups(),
 				test.allowRestoreSnapshots,
+				logger,
 			).(*restoreController)
 
 			if test.restore != nil {

pkg/controller/schedule_controller.go

@@ -18,13 +18,13 @@ package controller
 
 import (
 	"context"
-	"errors"
 	"fmt"
 	"sync"
 	"time"
 
-	"github.com/golang/glog"
+	"github.com/pkg/errors"
 	"github.com/robfig/cron"
+	"github.com/sirupsen/logrus"
 
 	apierrors "k8s.io/apimachinery/pkg/api/errors"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
@@ -39,6 +39,7 @@ import (
 	arkv1client "github.com/heptio/ark/pkg/generated/clientset/typed/ark/v1"
 	informers "github.com/heptio/ark/pkg/generated/informers/externalversions/ark/v1"
 	listers "github.com/heptio/ark/pkg/generated/listers/ark/v1"
+	kubeutil "github.com/heptio/ark/pkg/util/kube"
 )
 
 type scheduleController struct {
@@ -50,6 +51,7 @@ type scheduleController struct {
 	queue                 workqueue.RateLimitingInterface
 	syncPeriod            time.Duration
 	clock                 clock.Clock
+	logger                *logrus.Logger
 }
 
 func NewScheduleController(
@@ -57,9 +59,10 @@ func NewScheduleController(
 	backupsClient arkv1client.BackupsGetter,
 	schedulesInformer informers.ScheduleInformer,
 	syncPeriod time.Duration,
+	logger *logrus.Logger,
 ) *scheduleController {
 	if syncPeriod < time.Minute {
-		glog.Infof("Schedule sync period %v is too short. Setting to 1 minute", syncPeriod)
+		logger.WithField("syncPeriod", syncPeriod).Info("Provided schedule sync period is too short. Setting to 1 minute")
 		syncPeriod = time.Minute
 	}
 
@@ -71,6 +74,7 @@ func NewScheduleController(
 		queue:      workqueue.NewNamedRateLimitingQueue(workqueue.DefaultControllerRateLimiter(), "schedule"),
 		syncPeriod: syncPeriod,
 		clock:      clock.RealClock{},
+		logger:     logger,
 	}
 
 	c.syncHandler = c.processSchedule
@@ -84,13 +88,16 @@ func NewScheduleController(
 				case "", api.SchedulePhaseNew, api.SchedulePhaseEnabled:
 					// add to work queue
 				default:
-					glog.V(4).Infof("Schedule %s/%s has phase %s - skipping", schedule.Namespace, schedule.Name, schedule.Status.Phase)
+					c.logger.WithFields(logrus.Fields{
+						"schedule": kubeutil.NamespaceAndName(schedule),
+						"phase":    schedule.Status.Phase,
+					}).Debug("Schedule is not new, skipping")
 					return
 				}
 
 				key, err := cache.MetaNamespaceKeyFunc(schedule)
 				if err != nil {
-					glog.Errorf("error creating queue key for %#v: %v", schedule, err)
+					c.logger.WithError(errors.WithStack(err)).WithField("schedule", schedule).Error("Error creating queue key, item not added to queue")
 					return
 				}
 				c.queue.Add(key)
@@ -108,7 +115,7 @@ func (controller *scheduleController) Run(ctx context.Context, numWorkers int) e
 	var wg sync.WaitGroup
 
 	defer func() {
-		glog.Infof("Waiting for workers to finish their work")
+		controller.logger.Info("Waiting for workers to finish their work")
 
 		controller.queue.ShutDown()
 
@@ -117,17 +124,17 @@ func (controller *scheduleController) Run(ctx context.Context, numWorkers int) e
 		// we want to shut down the queue via defer and not at the end of the body.
 		wg.Wait()
 
-		glog.Infof("All workers have finished")
+		controller.logger.Info("All workers have finished")
 	}()
 
-	glog.Info("Starting ScheduleController")
-	defer glog.Info("Shutting down ScheduleController")
+	controller.logger.Info("Starting ScheduleController")
+	defer controller.logger.Info("Shutting down ScheduleController")
 
-	glog.Info("Waiting for caches to sync")
+	controller.logger.Info("Waiting for caches to sync")
 	if !cache.WaitForCacheSync(ctx.Done(), controller.schedulesListerSynced) {
 		return errors.New("timed out waiting for caches to sync")
 	}
-	glog.Info("Caches are synced")
+	controller.logger.Info("Caches are synced")
 
 	wg.Add(numWorkers)
 	for i := 0; i < numWorkers; i++ {
@@ -146,7 +153,7 @@ func (controller *scheduleController) Run(ctx context.Context, numWorkers int) e
 func (controller *scheduleController) enqueueAllEnabledSchedules() {
 	schedules, err := controller.schedulesLister.Schedules(api.DefaultNamespace).List(labels.NewSelector())
 	if err != nil {
-		glog.Errorf("error listing schedules: %v", err)
+		controller.logger.WithError(errors.WithStack(err)).Error("Error listing Schedules")
 		return
 	}
 
@@ -157,7 +164,7 @@ func (controller *scheduleController) enqueueAllEnabledSchedules() {
 
 		key, err := cache.MetaNamespaceKeyFunc(schedule)
 		if err != nil {
-			glog.Errorf("error creating queue key for %#v: %v", schedule, err)
+			controller.logger.WithError(errors.WithStack(err)).WithField("schedule", schedule).Error("Error creating queue key, item not added to queue")
 			continue
 		}
 		controller.queue.Add(key)
@@ -188,7 +195,7 @@ func (controller *scheduleController) processNextWorkItem() bool {
 		return true
 	}
 
-	glog.Errorf("syncHandler error: %v", err)
+	controller.logger.WithError(err).WithField("key", key).Error("Error in syncHandler, re-adding item to queue")
 	// we had an error processing the item so add it back
 	// into the queue for re-processing with rate-limiting
 	controller.queue.AddRateLimited(key)
@@ -197,23 +204,23 @@ func (controller *scheduleController) processNextWorkItem() bool {
 }
 
 func (controller *scheduleController) processSchedule(key string) error {
-	glog.V(4).Infof("processSchedule for key %q", key)
+	logContext := controller.logger.WithField("key", key)
+
+	logContext.Debug("Running processSchedule")
 	ns, name, err := cache.SplitMetaNamespaceKey(key)
 	if err != nil {
-		glog.V(4).Infof("error splitting key %q: %v", key, err)
-		return err
+		return errors.Wrap(err, "error splitting queue key")
 	}
 
-	glog.V(4).Infof("Getting schedule %s", key)
+	logContext.Debug("Getting Schedule")
 	schedule, err := controller.schedulesLister.Schedules(ns).Get(name)
 	if err != nil {
 		// schedule no longer exists
 		if apierrors.IsNotFound(err) {
-			glog.V(4).Infof("schedule %s not found: %v", key, err)
+			logContext.WithError(err).Debug("Schedule not found")
 			return nil
 		}
-		glog.V(4).Infof("error getting schedule %s: %v", key, err)
-		return err
+		return errors.Wrap(err, "error getting Schedule")
 	}
 
 	switch schedule.Status.Phase {
@@ -223,11 +230,10 @@ func (controller *scheduleController) processSchedule(key string) error {
 		return nil
 	}
 
-	glog.V(4).Infof("Cloning schedule %s", key)
+	logContext.Debug("Cloning schedule")
 	// don't modify items in the cache
 	schedule, err = cloneSchedule(schedule)
 	if err != nil {
-		glog.V(4).Infof("error cloning schedule %s: %v", key, err)
 		return err
 	}
 
@@ -235,7 +241,7 @@ func (controller *scheduleController) processSchedule(key string) error {
 	// so re-validate
 	currentPhase := schedule.Status.Phase
 
-	cronSchedule, errs := parseCronSchedule(schedule)
+	cronSchedule, errs := parseCronSchedule(schedule, controller.logger)
 	if len(errs) > 0 {
 		schedule.Status.Phase = api.SchedulePhaseFailedValidation
 		schedule.Status.ValidationErrors = errs
@@ -247,8 +253,7 @@ func (controller *scheduleController) processSchedule(key string) error {
 	if currentPhase != schedule.Status.Phase {
 		updatedSchedule, err := controller.schedulesClient.Schedules(ns).Update(schedule)
 		if err != nil {
-			glog.V(4).Infof("error updating status to %s: %v", schedule.Status.Phase, err)
-			return err
+			return errors.Wrapf(err, "error updating Schedule phase to %s", schedule.Status.Phase)
 		}
 		schedule = updatedSchedule
 	}
@@ -259,7 +264,6 @@ func (controller *scheduleController) processSchedule(key string) error {
 
 	// check for the schedule being due to run, and submit a Backup if so
 	if err := controller.submitBackupIfDue(schedule, cronSchedule); err != nil {
-		glog.V(4).Infof("error processing Schedule %v/%v: err=%v", schedule.Namespace, schedule.Name, err)
 		return err
 	}
 
@@ -269,18 +273,18 @@ func (controller *scheduleController) processSchedule(key string) error {
 func cloneSchedule(in interface{}) (*api.Schedule, error) {
 	clone, err := scheme.Scheme.DeepCopy(in)
 	if err != nil {
-		return nil, err
+		return nil, errors.Wrap(err, "error deep-copying Schedule")
 	}
 
 	out, ok := clone.(*api.Schedule)
 	if !ok {
-		return nil, fmt.Errorf("unexpected type: %T", clone)
+		return nil, errors.Errorf("unexpected type: %T", clone)
 	}
 
 	return out, nil
 }
 
-func parseCronSchedule(itm *api.Schedule) (cron.Schedule, []string) {
+func parseCronSchedule(itm *api.Schedule, logger *logrus.Logger) (cron.Schedule, []string) {
 	var validationErrors []string
 	var schedule cron.Schedule
 
@@ -290,18 +294,23 @@ func parseCronSchedule(itm *api.Schedule) (cron.Schedule, []string) {
 		return nil, validationErrors
 	}
 
+	logContext := logger.WithField("schedule", kubeutil.NamespaceAndName(itm))
+
 	// adding a recover() around cron.Parse because it panics on empty string and is possible
 	// that it panics under other scenarios as well.
 	func() {
 		defer func() {
 			if r := recover(); r != nil {
-				glog.V(4).Infof("panic parsing schedule %v/%v, cron schedule=%v: %v", itm.Namespace, itm.Name, itm.Spec.Schedule, r)
+				logContext.WithFields(logrus.Fields{
+					"schedule": itm.Spec.Schedule,
+					"recover":  r,
+				}).Debug("Panic parsing schedule")
 				validationErrors = append(validationErrors, fmt.Sprintf("invalid schedule: %v", r))
 			}
 		}()
 
 		if res, err := cron.ParseStandard(itm.Spec.Schedule); err != nil {
-			glog.V(4).Infof("error parsing schedule %v/%v, cron schedule=%v: %v", itm.Namespace, itm.Name, itm.Spec.Schedule, err)
+			logContext.WithError(errors.WithStack(err)).WithField("schedule", itm.Spec.Schedule).Debug("Error parsing schedule")
 			validationErrors = append(validationErrors, fmt.Sprintf("invalid schedule: %v", err))
 		} else {
 			schedule = res
@@ -316,12 +325,14 @@ func parseCronSchedule(itm *api.Schedule) (cron.Schedule, []string) {
 }
 
 func (controller *scheduleController) submitBackupIfDue(item *api.Schedule, cronSchedule cron.Schedule) error {
-	now := controller.clock.Now()
-
-	isDue, nextRunTime := getNextRunTime(item, cronSchedule, now)
+	var (
+		now                = controller.clock.Now()
+		isDue, nextRunTime = getNextRunTime(item, cronSchedule, now)
+		logContext         = controller.logger.WithField("schedule", kubeutil.NamespaceAndName(item))
+	)
 
 	if !isDue {
-		glog.Infof("Next run time for %v/%v is %v, skipping...", item.Namespace, item.Name, nextRunTime)
+		logContext.WithField("nextRunTime", nextRunTime).Info("Schedule is not due, skipping")
 		return nil
 	}
 
@@ -331,25 +342,21 @@ func (controller *scheduleController) submitBackupIfDue(item *api.Schedule, cron
 	// It might also make sense in the future to explicitly check for currently-running
 	// backups so that we don't overlap runs (for disk snapshots in particular, this can
 	// lead to performance issues).
-
-	glog.Infof("Next run time for %v/%v is %v, submitting Backup...", item.Namespace, item.Name, nextRunTime)
+	logContext.WithField("nextRunTime", nextRunTime).Info("Schedule is due, submitting Backup")
 	backup := getBackup(item, now)
 	if _, err := controller.backupsClient.Backups(backup.Namespace).Create(backup); err != nil {
-		glog.V(4).Infof("error creating Backup: %v", err)
-		return err
+		return errors.Wrap(err, "error creating Backup")
 	}
 
 	schedule, err := cloneSchedule(item)
 	if err != nil {
-		glog.V(4).Infof("error cloning Schedule %v/%v: %v", item.Namespace, item.Name, err)
 		return err
 	}
 
 	schedule.Status.LastBackup = metav1.NewTime(now)
 
 	if _, err := controller.schedulesClient.Schedules(schedule.Namespace).Update(schedule); err != nil {
-		glog.V(4).Infof("error updating LastBackup for Schedule %v/%v: %v", schedule.Namespace, schedule.Name, err)
-		return err
+		return errors.Wrapf(err, "error updating Schedule's LastBackup time to %v", schedule.Status.LastBackup)
 	}
 
 	return nil

pkg/controller/schedule_controller_test.go

@@ -21,6 +21,7 @@ import (
 	"time"
 
 	"github.com/robfig/cron"
+	testlogger "github.com/sirupsen/logrus/hooks/test"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 
@@ -123,6 +124,7 @@ func TestProcessSchedule(t *testing.T) {
 			var (
 				client          = fake.NewSimpleClientset()
 				sharedInformers = informers.NewSharedInformerFactory(client, 0)
+				logger, _       = testlogger.NewNullLogger()
 			)
 
 			c := NewScheduleController(
@@ -130,6 +132,7 @@ func TestProcessSchedule(t *testing.T) {
 				client.ArkV1(),
 				sharedInformers.Ark().V1().Schedules(),
 				time.Duration(0),
+				logger,
 			)
 
 			var (
@@ -291,7 +294,9 @@ func TestParseCronSchedule(t *testing.T) {
 		},
 	}
 
-	c, errs := parseCronSchedule(s)
+	logger, _ := testlogger.NewNullLogger()
+
+	c, errs := parseCronSchedule(s, logger)
 	require.Empty(t, errs)
 
 	// make sure we're not due and next backup is tomorrow at 9am

pkg/discovery/helper.go

@@ -21,6 +21,8 @@ import (
 	"sync"
 
 	kcmdutil "github.com/heptio/ark/third_party/kubernetes/pkg/kubectl/cmd/util"
+	"github.com/pkg/errors"
+	"github.com/sirupsen/logrus"
 
 	"k8s.io/apimachinery/pkg/api/meta"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
@@ -52,6 +54,7 @@ type Helper interface {
 
 type helper struct {
 	discoveryClient discovery.DiscoveryInterface
+	logger          *logrus.Logger
 
 	// lock guards mapper and resources
 	lock      sync.RWMutex
@@ -61,7 +64,7 @@ type helper struct {
 
 var _ Helper = &helper{}
 
-func NewHelper(discoveryClient discovery.DiscoveryInterface) (Helper, error) {
+func NewHelper(discoveryClient discovery.DiscoveryInterface, logger *logrus.Logger) (Helper, error) {
 	h := &helper{
 		discoveryClient: discoveryClient,
 	}
@@ -77,18 +80,18 @@ func (h *helper) Refresh() error {
 
 	groupResources, err := discovery.GetAPIGroupResources(h.discoveryClient)
 	if err != nil {
-		return err
+		return errors.WithStack(err)
 	}
 	mapper := discovery.NewRESTMapper(groupResources, dynamic.VersionInterfaces)
-	shortcutExpander, err := kcmdutil.NewShortcutExpander(mapper, h.discoveryClient)
+	shortcutExpander, err := kcmdutil.NewShortcutExpander(mapper, h.discoveryClient, h.logger)
 	if err != nil {
-		return err
+		return errors.WithStack(err)
 	}
 	h.mapper = shortcutExpander
 
 	preferredResources, err := h.discoveryClient.ServerPreferredResources()
 	if err != nil {
-		return err
+		return errors.WithStack(err)
 	}
 
 	h.resources = discovery.FilteredBy(

pkg/restore/resource_waiter.go

@@ -17,10 +17,10 @@ limitations under the License.
 package restore
 
 import (
-	"errors"
-	"fmt"
 	"time"
 
+	"github.com/pkg/errors"
+
 	"k8s.io/apimachinery/pkg/apis/meta/v1/unstructured"
 	"k8s.io/apimachinery/pkg/runtime"
 	"k8s.io/apimachinery/pkg/util/sets"
@@ -69,7 +69,7 @@ func (rw *resourceWaiter) Wait() error {
 		case event := <-rw.watchChan:
 			obj, ok := event.Object.(*unstructured.Unstructured)
 			if !ok {
-				return fmt.Errorf("Unexpected type %T", event.Object)
+				return errors.Errorf("Unexpected type %T", event.Object)
 			}
 
 			if event.Type == watch.Added || event.Type == watch.Modified {

pkg/restore/restore.go

@@ -28,6 +28,8 @@ import (
 	"sort"
 	"time"
 
+	"github.com/sirupsen/logrus"
+
 	apierrors "k8s.io/apimachinery/pkg/api/errors"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"k8s.io/apimachinery/pkg/apis/meta/v1/unstructured"
@@ -37,7 +39,6 @@ import (
 	corev1 "k8s.io/client-go/kubernetes/typed/core/v1"
 	"k8s.io/client-go/pkg/api/v1"
 
-	"github.com/golang/glog"
 	api "github.com/heptio/ark/pkg/apis/ark/v1"
 	"github.com/heptio/ark/pkg/client"
 	"github.com/heptio/ark/pkg/cloudprovider"
@@ -69,12 +70,13 @@ type kubernetesRestorer struct {
 	namespaceClient    corev1.NamespaceInterface
 	resourcePriorities []string
 	fileSystem         FileSystem
+	logger             *logrus.Logger
 }
 
 // prioritizeResources takes a list of pre-prioritized resources and a full list of resources to restore,
 // and returns an ordered list of GroupResource-resolved resources in the order that they should be
 // restored.
-func prioritizeResources(helper discovery.Helper, priorities []string, includedResources *collections.IncludesExcludes) ([]schema.GroupResource, error) {
+func prioritizeResources(helper discovery.Helper, priorities []string, includedResources *collections.IncludesExcludes, logger *logrus.Logger) ([]schema.GroupResource, error) {
 	var ret []schema.GroupResource
 
 	// set keeps track of resolved GroupResource names
@@ -88,7 +90,7 @@ func prioritizeResources(helper discovery.Helper, priorities []string, includedR
 		}
 
 		if !includedResources.ShouldInclude(gr.String()) {
-			glog.Infof("Not including resource %v", gr)
+			logger.WithField("groupResource", gr).Info("Not including resource")
 			continue
 		}
 
@@ -109,7 +111,7 @@ func prioritizeResources(helper discovery.Helper, priorities []string, includedR
 			gr := groupVersion.WithResource(resource.Name).GroupResource()
 
 			if !includedResources.ShouldInclude(gr.String()) {
-				glog.Infof("Not including resource %v", gr)
+				logger.WithField("groupResource", gr).Info("Not including resource")
 				continue
 			}
 
@@ -139,6 +141,7 @@ func NewKubernetesRestorer(
 	resourcePriorities []string,
 	backupClient arkv1client.BackupsGetter,
 	namespaceClient corev1.NamespaceInterface,
+	logger *logrus.Logger,
 ) (Restorer, error) {
 	r := make(map[schema.GroupResource]restorers.ResourceRestorer)
 	for gr, restorer := range customRestorers {
@@ -158,6 +161,7 @@ func NewKubernetesRestorer(
 		namespaceClient:    namespaceClient,
 		resourcePriorities: resourcePriorities,
 		fileSystem:         &osFileSystem{},
+		logger:             logger,
 	}, nil
 }
 
@@ -183,17 +187,18 @@ func (kr *kubernetesRestorer) Restore(restore *api.Restore, backup *api.Backup,
 	resourceIncludesExcludes := collections.GenerateIncludesExcludes(
 		restore.Spec.IncludedResources,
 		restore.Spec.ExcludedResources,
-		func(item string) (string, error) {
+		func(item string) string {
 			gr, err := kr.discoveryHelper.ResolveGroupResource(item)
 			if err != nil {
-				return "", err
+				kr.logger.WithError(err).WithField("resource", item).Error("Unable to resolve resource")
+				return ""
 			}
 
-			return gr.String(), nil
+			return gr.String()
 		},
 	)
 
-	prioritizedResources, err := prioritizeResources(kr.discoveryHelper, kr.resourcePriorities, resourceIncludesExcludes)
+	prioritizedResources, err := prioritizeResources(kr.discoveryHelper, kr.resourcePriorities, resourceIncludesExcludes, kr.logger)
 	if err != nil {
 		return api.RestoreResult{}, api.RestoreResult{Ark: []string{err.Error()}}
 	}

pkg/restore/restore_test.go

@@ -23,6 +23,7 @@ import (
 	"os"
 	"testing"
 
+	"github.com/sirupsen/logrus/hooks/test"
 	"github.com/spf13/afero"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
@@ -80,6 +81,8 @@ func TestPrioritizeResources(t *testing.T) {
 		},
 	}
 
+	logger, _ := test.NewNullLogger()
+
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
 			helper := &FakeDiscoveryHelper{RESTMapper: &FakeMapper{AutoReturnResource: true}}
@@ -94,7 +97,7 @@ func TestPrioritizeResources(t *testing.T) {
 
 			includesExcludes := collections.NewIncludesExcludes().Includes(test.includes...).Excludes(test.excludes...)
 
-			result, err := prioritizeResources(helper, test.priorities, includesExcludes)
+			result, err := prioritizeResources(helper, test.priorities, includesExcludes, logger)
 			if err != nil {
 				t.Fatalf("unexpected error: %v", err)
 			}

pkg/restore/restorers/job_restorer.go

@@ -17,7 +17,7 @@ limitations under the License.
 package restorers
 
 import (
-	"github.com/golang/glog"
+	"github.com/sirupsen/logrus"
 
 	"k8s.io/apimachinery/pkg/runtime"
 
@@ -25,12 +25,16 @@ import (
 	"github.com/heptio/ark/pkg/util/collections"
 )
 
-type jobRestorer struct{}
+type jobRestorer struct {
+	logger *logrus.Logger
+}
 
 var _ ResourceRestorer = &jobRestorer{}
 
-func NewJobRestorer() ResourceRestorer {
-	return &jobRestorer{}
+func NewJobRestorer(logger *logrus.Logger) ResourceRestorer {
+	return &jobRestorer{
+		logger: logger,
+	}
 }
 
 func (r *jobRestorer) Handles(obj runtime.Unstructured, restore *api.Restore) bool {
@@ -38,25 +42,25 @@ func (r *jobRestorer) Handles(obj runtime.Unstructured, restore *api.Restore) bo
 }
 
 func (r *jobRestorer) Prepare(obj runtime.Unstructured, restore *api.Restore, backup *api.Backup) (runtime.Unstructured, error, error) {
-	glog.V(4).Infof("resetting metadata and status")
+	r.logger.Debug("resetting metadata and status")
 	_, err := resetMetadataAndStatus(obj, true)
 	if err != nil {
 		return nil, nil, err
 	}
 
-	glog.V(4).Infof("getting spec.selector.matchLabels")
-	matchLabels, err := collections.GetMap(obj.UnstructuredContent(), "spec.selector.matchLabels")
-	if err != nil {
-		glog.V(4).Infof("unable to get spec.selector.matchLabels: %v", err)
-	} else {
-		delete(matchLabels, "controller-uid")
+	fieldDeletions := map[string]string{
+		"spec.selector.matchLabels":     "controller-uid",
+		"spec.template.metadata.labels": "controller-uid",
 	}
 
-	templateLabels, err := collections.GetMap(obj.UnstructuredContent(), "spec.template.metadata.labels")
-	if err != nil {
-		glog.V(4).Infof("unable to get spec.template.metadata.labels: %v", err)
-	} else {
-		delete(templateLabels, "controller-uid")
+	for k, v := range fieldDeletions {
+		r.logger.Debugf("Getting %s", k)
+		labels, err := collections.GetMap(obj.UnstructuredContent(), k)
+		if err != nil {
+			r.logger.WithError(err).Debugf("Unable to get %s", k)
+		} else {
+			delete(labels, v)
+		}
 	}
 
 	return obj, nil, nil

pkg/restore/restorers/job_restorer_test.go

@@ -19,6 +19,7 @@ package restorers
 import (
 	"testing"
 
+	testlogger "github.com/sirupsen/logrus/hooks/test"
 	"github.com/stretchr/testify/assert"
 
 	"k8s.io/apimachinery/pkg/runtime"
@@ -126,7 +127,10 @@ func TestJobRestorerPrepare(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			restorer := NewJobRestorer()
+			var (
+				logger, _ = testlogger.NewNullLogger()
+				restorer  = NewJobRestorer(logger)
+			)
 
 			res, _, err := restorer.Prepare(test.obj, nil, nil)
 

pkg/restore/restorers/pod_restorer.go

@@ -19,7 +19,7 @@ package restorers
 import (
 	"regexp"
 
-	"github.com/golang/glog"
+	"github.com/sirupsen/logrus"
 
 	"k8s.io/apimachinery/pkg/runtime"
 
@@ -27,12 +27,16 @@ import (
 	"github.com/heptio/ark/pkg/util/collections"
 )
 
-type podRestorer struct{}
+type podRestorer struct {
+	logger *logrus.Logger
+}
 
 var _ ResourceRestorer = &podRestorer{}
 
-func NewPodRestorer() ResourceRestorer {
-	return &podRestorer{}
+func NewPodRestorer(logger *logrus.Logger) ResourceRestorer {
+	return &podRestorer{
+		logger: logger,
+	}
 }
 
 func (nsr *podRestorer) Handles(obj runtime.Unstructured, restore *api.Restore) bool {
@@ -43,37 +47,36 @@ var (
 	defaultTokenRegex = regexp.MustCompile("default-token-.*")
 )
 
-func (nsr *podRestorer) Prepare(obj runtime.Unstructured, restore *api.Restore, backup *api.Backup) (runtime.Unstructured, error, error) {
-	glog.V(4).Infof("resetting metadata and status")
+func (r *podRestorer) Prepare(obj runtime.Unstructured, restore *api.Restore, backup *api.Backup) (runtime.Unstructured, error, error) {
+	r.logger.Debug("resetting metadata and status")
 	_, err := resetMetadataAndStatus(obj, true)
 	if err != nil {
 		return nil, nil, err
 	}
 
-	glog.V(4).Infof("getting spec")
+	r.logger.Debug("getting spec")
 	spec, err := collections.GetMap(obj.UnstructuredContent(), "spec")
 	if err != nil {
 		return nil, nil, err
 	}
 
-	glog.V(4).Infof("deleting spec.NodeName")
+	r.logger.Debug("deleting spec.NodeName")
 	delete(spec, "nodeName")
 
 	newVolumes := make([]interface{}, 0)
-	glog.V(4).Infof("iterating over volumes")
+	r.logger.Debug("iterating over volumes")
 	err = collections.ForEach(spec, "volumes", func(volume map[string]interface{}) error {
 		name, err := collections.GetString(volume, "name")
 		if err != nil {
 			return err
 		}
 
-		glog.V(4).Infof("checking volume with name %q", name)
-
+		r.logger.WithField("volumeName", name).Debug("Checking volume")
 		if !defaultTokenRegex.MatchString(name) {
-			glog.V(4).Infof("preserving volume")
+			r.logger.WithField("volumeName", name).Debug("Preserving volume")
 			newVolumes = append(newVolumes, volume)
 		} else {
-			glog.V(4).Infof("excluding volume")
+			r.logger.WithField("volumeName", name).Debug("Excluding volume")
 		}
 
 		return nil
@@ -82,10 +85,10 @@ func (nsr *podRestorer) Prepare(obj runtime.Unstructured, restore *api.Restore,
 		return nil, nil, err
 	}
 
-	glog.V(4).Infof("setting spec.volumes")
+	r.logger.Debug("Setting spec.volumes")
 	spec["volumes"] = newVolumes
 
-	glog.V(4).Infof("iterating over containers")
+	r.logger.Debug("iterating over containers")
 	err = collections.ForEach(spec, "containers", func(container map[string]interface{}) error {
 		var newVolumeMounts []interface{}
 		err := collections.ForEach(container, "volumeMounts", func(volumeMount map[string]interface{}) error {
@@ -94,13 +97,12 @@ func (nsr *podRestorer) Prepare(obj runtime.Unstructured, restore *api.Restore,
 				return err
 			}
 
-			glog.V(4).Infof("checking volumeMount with name %q", name)
-
+			r.logger.WithField("volumeMount", name).Debug("Checking volumeMount")
 			if !defaultTokenRegex.MatchString(name) {
-				glog.V(4).Infof("preserving volumeMount")
+				r.logger.WithField("volumeMount", name).Debug("Preserving volumeMount")
 				newVolumeMounts = append(newVolumeMounts, volumeMount)
 			} else {
-				glog.V(4).Infof("excluding volumeMount")
+				r.logger.WithField("volumeMount", name).Debug("Excluding volumeMount")
 			}
 
 			return nil

pkg/restore/restorers/pod_restorer_test.go

@@ -19,6 +19,7 @@ package restorers
 import (
 	"testing"
 
+	testlogger "github.com/sirupsen/logrus/hooks/test"
 	"github.com/stretchr/testify/assert"
 
 	"k8s.io/apimachinery/pkg/runtime"
@@ -96,7 +97,10 @@ func TestPodRestorerPrepare(t *testing.T) {
 
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
-			restorer := NewPodRestorer()
+			var (
+				logger, _ = testlogger.NewNullLogger()
+				restorer  = NewPodRestorer(logger)
+			)
 
 			res, _, err := restorer.Prepare(test.obj, nil, nil)
 

pkg/restore/restorers/pv_restorer.go

@@ -17,8 +17,7 @@ limitations under the License.
 package restorers
 
 import (
-	"errors"
-	"fmt"
+	"github.com/pkg/errors"
 
 	"k8s.io/apimachinery/pkg/runtime"
 
@@ -83,7 +82,7 @@ func (sr *persistentVolumeRestorer) Prepare(obj runtime.Unstructured, restore *a
 		// if there are snapshots, and this is a supported PV type, but there's no
 		// snapshot for this PV, it's an error
 		if backup.Status.VolumeBackups[pvName] == nil {
-			return nil, nil, fmt.Errorf("no snapshot found to restore volume %s from", pvName)
+			return nil, nil, errors.Errorf("no snapshot found to restore volume %s from", pvName)
 		}
 
 		restoreFromSnapshot = true

pkg/util/collections/includes_excludes.go

@@ -17,10 +17,7 @@ limitations under the License.
 package collections
 
 import (
-	"errors"
-	"fmt"
-
-	"github.com/golang/glog"
+	"github.com/pkg/errors"
 
 	"k8s.io/apimachinery/pkg/util/sets"
 )
@@ -102,7 +99,7 @@ func ValidateIncludesExcludes(includesList, excludesList []string) []error {
 
 	for _, itm := range excludes.List() {
 		if includes.Has(itm) {
-			errs = append(errs, fmt.Errorf("excludes list cannot contain an item in the includes list: %v", itm))
+			errs = append(errs, errors.Errorf("excludes list cannot contain an item in the includes list: %v", itm))
 		}
 	}
 
@@ -113,7 +110,7 @@ func ValidateIncludesExcludes(includesList, excludesList []string) []error {
 // include/exclude slices, applying the specified mapping function to each item in them,
 // and adding the output of the function to the new struct. If the mapping function returns
 // an error for an item, it is omitted from the result.
-func GenerateIncludesExcludes(includes, excludes []string, mapFunc func(string) (string, error)) *IncludesExcludes {
+func GenerateIncludesExcludes(includes, excludes []string, mapFunc func(string) string) *IncludesExcludes {
 	res := NewIncludesExcludes()
 
 	for _, item := range includes {
@@ -122,22 +119,18 @@ func GenerateIncludesExcludes(includes, excludes []string, mapFunc func(string)
 			continue
 		}
 
-		key, err := mapFunc(item)
-		if err != nil {
-			glog.Errorf("unable to include item %q: %v", item, err)
+		key := mapFunc(item)
+		if key == "" {
 			continue
 		}
-
 		res.Includes(key)
 	}
 
 	for _, item := range excludes {
-		key, err := mapFunc(item)
-		if err != nil {
-			glog.Errorf("unable to exclude item %q: %v", item, err)
+		key := mapFunc(item)
+		if key == "" {
 			continue
 		}
-
 		res.Excludes(key)
 	}
 

pkg/util/collections/includes_excludes_test.go

@@ -17,10 +17,12 @@ limitations under the License.
 package collections
 
 import (
-	"errors"
 	"testing"
 
 	"github.com/stretchr/testify/assert"
+
+	"github.com/pkg/errors"
+	"github.com/stretchr/testify/require"
 )
 
 func TestShouldInclude(t *testing.T) {
@@ -126,7 +128,11 @@ func TestValidateIncludesExcludes(t *testing.T) {
 		t.Run(test.name, func(t *testing.T) {
 			res := ValidateIncludesExcludes(test.includes, test.excludes)
 
-			assert.Equal(t, test.expected, res)
+			require.Equal(t, len(test.expected), len(res))
+
+			for i := 0; i < len(test.expected); i++ {
+				assert.Equal(t, test.expected[i].Error(), res[i].Error())
+			}
 		})
 	}
 }

pkg/util/collections/map_utils.go

@@ -17,9 +17,9 @@ limitations under the License.
 package collections
 
 import (
-	"errors"
-	"fmt"
 	"strings"
+
+	"github.com/pkg/errors"
 )
 
 // GetValue returns the object at root[path], where path is a dot separated string.
@@ -33,7 +33,7 @@ func GetValue(root map[string]interface{}, path string) (interface{}, error) {
 
 	obj, found := root[pathParts[0]]
 	if !found {
-		return "", fmt.Errorf("key %v not found", pathParts[0])
+		return "", errors.Errorf("key %v not found", pathParts[0])
 	}
 
 	if len(pathParts) == 1 {
@@ -42,7 +42,7 @@ func GetValue(root map[string]interface{}, path string) (interface{}, error) {
 
 	subMap, ok := obj.(map[string]interface{})
 	if !ok {
-		return "", fmt.Errorf("value at key %v is not a map[string]interface{}", key)
+		return "", errors.Errorf("value at key %v is not a map[string]interface{}", key)
 	}
 
 	return GetValue(subMap, strings.Join(pathParts[1:], "."))
@@ -57,7 +57,7 @@ func GetString(root map[string]interface{}, path string) (string, error) {
 
 	str, ok := obj.(string)
 	if !ok {
-		return "", fmt.Errorf("value at path %v is not a string", path)
+		return "", errors.Errorf("value at path %v is not a string", path)
 	}
 
 	return str, nil
@@ -72,7 +72,7 @@ func GetMap(root map[string]interface{}, path string) (map[string]interface{}, e
 
 	ret, ok := obj.(map[string]interface{})
 	if !ok {
-		return nil, fmt.Errorf("value at path %v is not a map[string]interface{}", path)
+		return nil, errors.Errorf("value at path %v is not a map[string]interface{}", path)
 	}
 
 	return ret, nil
@@ -87,7 +87,7 @@ func GetSlice(root map[string]interface{}, path string) ([]interface{}, error) {
 
 	ret, ok := obj.([]interface{})
 	if !ok {
-		return nil, fmt.Errorf("value at path %v is not a []interface{}", path)
+		return nil, errors.Errorf("value at path %v is not a []interface{}", path)
 	}
 
 	return ret, nil
@@ -103,7 +103,7 @@ func ForEach(root map[string]interface{}, path string, fn func(obj map[string]in
 	for i := range s {
 		obj, ok := s[i].(map[string]interface{})
 		if !ok {
-			return fmt.Errorf("unable to convert %s[%d] to an object", path, i)
+			return errors.Errorf("unable to convert %s[%d] to an object", path, i)
 		}
 		if err := fn(obj); err != nil {
 			return err

pkg/util/encode/encode.go

@@ -21,6 +21,8 @@ import (
 	"fmt"
 	"io"
 
+	"github.com/pkg/errors"
+
 	"k8s.io/apimachinery/pkg/runtime"
 
 	"github.com/heptio/ark/pkg/apis/ark/v1"
@@ -46,7 +48,7 @@ func EncodeTo(obj runtime.Object, format string, w io.Writer) error {
 		return err
 	}
 
-	return encoder.Encode(obj, w)
+	return errors.WithStack(encoder.Encode(obj, w))
 }
 
 // EncoderFor gets the appropriate encoder for the specified format.
@@ -55,7 +57,7 @@ func EncoderFor(format string) (runtime.Encoder, error) {
 	desiredMediaType := fmt.Sprintf("application/%s", format)
 	serializerInfo, found := runtime.SerializerInfoForMediaType(scheme.Codecs.SupportedMediaTypes(), desiredMediaType)
 	if !found {
-		return nil, fmt.Errorf("unable to locate an encoder for %q", desiredMediaType)
+		return nil, errors.Errorf("unable to locate an encoder for %q", desiredMediaType)
 	}
 	if serializerInfo.PrettySerializer != nil {
 		encoder = serializerInfo.PrettySerializer

pkg/util/kube/utils.go

@@ -17,11 +17,12 @@ limitations under the License.
 package kube
 
 import (
-	"errors"
 	"fmt"
 	"regexp"
 	"strings"
 
+	"github.com/pkg/errors"
+
 	apierrors "k8s.io/apimachinery/pkg/api/errors"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	corev1 "k8s.io/client-go/kubernetes/typed/core/v1"
@@ -50,7 +51,7 @@ func EnsureNamespaceExists(namespace *v1.Namespace, client corev1.NamespaceInter
 	} else if apierrors.IsAlreadyExists(err) {
 		return false, nil
 	} else {
-		return false, err
+		return false, errors.Wrapf(err, "error creating namespace %s", namespace.Name)
 	}
 }
 

pkg/util/logging/error_location_hook.go

@@ -0,0 +1,81 @@
+package logging
+
+import (
+	"fmt"
+
+	"github.com/pkg/errors"
+	"github.com/sirupsen/logrus"
+)
+
+const (
+	errorFileField     = "error.file"
+	errorFunctionField = "error.function"
+)
+
+// ErrorLocationHook is a logrus hook that attaches error location information
+// to log entries if an error is being logged and it has stack-trace information
+// (i.e. if it originates from or is wrapped by github.com/pkg/errors)
+type ErrorLocationHook struct {
+}
+
+func (h *ErrorLocationHook) Levels() []logrus.Level {
+	return logrus.AllLevels
+}
+
+func (h *ErrorLocationHook) Fire(entry *logrus.Entry) error {
+	var (
+		errObj interface{}
+		exists bool
+	)
+
+	if errObj, exists = entry.Data[logrus.ErrorKey]; !exists {
+		return nil
+	}
+
+	err, ok := errObj.(error)
+	if !ok {
+		return errors.New("object logged as error does not satisfy error interface")
+	}
+
+	stackErr := getInnermostTrace(err)
+
+	if stackErr != nil {
+		stackTrace := stackErr.StackTrace()
+		functionName := fmt.Sprintf("%n", stackTrace[0])
+		fileAndLine := fmt.Sprintf("%s:%d", stackTrace[0], stackTrace[0])
+
+		entry.Data[errorFileField] = fileAndLine
+		entry.Data[errorFunctionField] = functionName
+	}
+
+	return nil
+}
+
+type stackTracer interface {
+	error
+	StackTrace() errors.StackTrace
+}
+
+type causer interface {
+	Cause() error
+}
+
+// getInnermostTrace returns the innermost error that
+// has a stack trace attached
+func getInnermostTrace(err error) stackTracer {
+	var tracer stackTracer
+
+	for {
+		t, isTracer := err.(stackTracer)
+		if isTracer {
+			tracer = t
+		}
+
+		c, isCauser := err.(causer)
+		if isCauser {
+			err = c.Cause()
+		} else {
+			return tracer
+		}
+	}
+}

pkg/util/logging/error_location_hook_test.go

@@ -0,0 +1,147 @@
+package logging
+
+import (
+	"errors"
+	"testing"
+
+	pkgerrs "github.com/pkg/errors"
+	"github.com/sirupsen/logrus"
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+)
+
+func TestFire(t *testing.T) {
+	tests := []struct {
+		name                string
+		preEntryFields      map[string]interface{}
+		expectedEntryFields map[string]interface{}
+		expectedErr         bool
+	}{
+		{
+			name:                "no error",
+			preEntryFields:      map[string]interface{}{"foo": "bar"},
+			expectedEntryFields: map[string]interface{}{"foo": "bar"},
+		},
+		{
+			name:                "basic (non-pkg/errors) error",
+			preEntryFields:      map[string]interface{}{logrus.ErrorKey: errors.New("a normal error")},
+			expectedEntryFields: map[string]interface{}{logrus.ErrorKey: errors.New("a normal error")},
+		},
+		{
+			name:                "non-error logged in error field",
+			preEntryFields:      map[string]interface{}{logrus.ErrorKey: "not an error"},
+			expectedEntryFields: map[string]interface{}{logrus.ErrorKey: "not an error"},
+			expectedErr:         true,
+		},
+		{
+			name:           "pkg/errors error",
+			preEntryFields: map[string]interface{}{logrus.ErrorKey: pkgerrs.New("a pkg/errors error")},
+			expectedEntryFields: map[string]interface{}{
+				logrus.ErrorKey:    pkgerrs.New("a pkg/errors error"),
+				errorFileField:     "",
+				errorFunctionField: "TestFire",
+			},
+		},
+	}
+
+	for _, test := range tests {
+		t.Run(test.name, func(t *testing.T) {
+			hook := &ErrorLocationHook{}
+
+			entry := &logrus.Entry{
+				Data: logrus.Fields(test.preEntryFields),
+			}
+
+			// method under test
+			err := hook.Fire(entry)
+
+			require.Equal(t, test.expectedErr, err != nil)
+			require.Equal(t, len(test.expectedEntryFields), len(entry.Data))
+
+			for key, expectedValue := range test.expectedEntryFields {
+				actualValue, found := entry.Data[key]
+				assert.True(t, found, "expected key not found: %s", key)
+
+				switch key {
+				// test existence of this field only since testing the value
+				// is fragile
+				case errorFileField:
+				case logrus.ErrorKey:
+					if err, ok := expectedValue.(error); ok {
+						assert.Equal(t, err.Error(), actualValue.(error).Error())
+					} else {
+						assert.Equal(t, expectedValue, actualValue)
+					}
+				default:
+					assert.Equal(t, expectedValue, actualValue)
+				}
+			}
+		})
+	}
+}
+
+func TestGetInnermostTrace(t *testing.T) {
+	newError := func() error {
+		return errors.New("a normal error")
+	}
+
+	tests := []struct {
+		name        string
+		err         error
+		expectedRes error
+	}{
+		{
+			name:        "normal error",
+			err:         newError(),
+			expectedRes: nil,
+		},
+		{
+			name:        "pkg/errs error",
+			err:         pkgerrs.New("a pkg/errs error"),
+			expectedRes: pkgerrs.New("a pkg/errs error"),
+		},
+		{
+			name:        "one level of stack-ing a normal error",
+			err:         pkgerrs.WithStack(newError()),
+			expectedRes: pkgerrs.WithStack(newError()),
+		},
+		{
+			name:        "two levels of stack-ing a normal error",
+			err:         pkgerrs.WithStack(pkgerrs.WithStack(newError())),
+			expectedRes: pkgerrs.WithStack(newError()),
+		},
+		{
+			name:        "one level of stack-ing a pkg/errors error",
+			err:         pkgerrs.WithStack(pkgerrs.New("a pkg/errs error")),
+			expectedRes: pkgerrs.New("a pkg/errs error"),
+		},
+		{
+			name:        "two levels of stack-ing a pkg/errors error",
+			err:         pkgerrs.WithStack(pkgerrs.WithStack(pkgerrs.New("a pkg/errs error"))),
+			expectedRes: pkgerrs.New("a pkg/errs error"),
+		},
+		{
+			name:        "two levels of wrapping a normal error",
+			err:         pkgerrs.Wrap(pkgerrs.Wrap(newError(), "wrap 1"), "wrap 2"),
+			expectedRes: pkgerrs.Wrap(newError(), "wrap 1"),
+		},
+		{
+			name:        "two levels of wrapping a pkg/errors error",
+			err:         pkgerrs.Wrap(pkgerrs.Wrap(pkgerrs.New("a pkg/errs error"), "wrap 1"), "wrap 2"),
+			expectedRes: pkgerrs.New("a pkg/errs error"),
+		},
+	}
+
+	for _, test := range tests {
+		t.Run(test.name, func(t *testing.T) {
+			res := getInnermostTrace(test.err)
+
+			if test.expectedRes == nil {
+				assert.Nil(t, res)
+				return
+			}
+
+			assert.Equal(t, test.expectedRes.Error(), res.Error())
+		})
+	}
+}

third_party/kubernetes/pkg/kubectl/cmd/util/shortcut_expander.go

@@ -20,7 +20,7 @@ import (
 	"errors"
 	"strings"
 
-	"github.com/golang/glog"
+	"github.com/sirupsen/logrus"
 
 	"k8s.io/apimachinery/pkg/api/meta"
 	"k8s.io/apimachinery/pkg/runtime/schema"
@@ -39,11 +39,12 @@ type shortcutExpander struct {
 	RESTMapper meta.RESTMapper
 
 	discoveryClient discovery.DiscoveryInterface
+	logger          *logrus.Logger
 }
 
 var _ meta.RESTMapper = &shortcutExpander{}
 
-func NewShortcutExpander(delegate meta.RESTMapper, client discovery.DiscoveryInterface) (shortcutExpander, error) {
+func NewShortcutExpander(delegate meta.RESTMapper, client discovery.DiscoveryInterface, logger *logrus.Logger) (shortcutExpander, error) {
 	if client == nil {
 		return shortcutExpander{}, errors.New("Please provide discovery client to shortcut expander")
 	}
@@ -96,7 +97,7 @@ func (e shortcutExpander) getShortcutMappings() ([]ResourceShortcuts, error) {
 				for _, shortName := range apiRes.ShortNames {
 					gv, err := schema.ParseGroupVersion(apiResources.GroupVersion)
 					if err != nil {
-						glog.V(1).Infof("Unable to parse groupversion = %s due to = %s", apiResources.GroupVersion, err.Error())
+						e.logger.WithError(err).WithField("groupVersion", apiResources.GroupVersion).Error("Unable to parse groupversion")
 						continue
 					}
 					rs := ResourceShortcuts{

vendor/github.com/pkg/errors/.gitignore

@@ -0,0 +1,24 @@
+# Compiled Object files, Static and Dynamic libs (Shared Objects)
+*.o
+*.a
+*.so
+
+# Folders
+_obj
+_test
+
+# Architecture specific extensions/prefixes
+*.[568vq]
+[568vq].out
+
+*.cgo1.go
+*.cgo2.c
+_cgo_defun.c
+_cgo_gotypes.go
+_cgo_export.*
+
+_testmain.go
+
+*.exe
+*.test
+*.prof

vendor/github.com/pkg/errors/LICENSE

@@ -0,0 +1,23 @@
+Copyright (c) 2015, Dave Cheney <dave@cheney.net>
+All rights reserved.
+
+Redistribution and use in source and binary forms, with or without
+modification, are permitted provided that the following conditions are met:
+
+* Redistributions of source code must retain the above copyright notice, this
+  list of conditions and the following disclaimer.
+
+* Redistributions in binary form must reproduce the above copyright notice,
+  this list of conditions and the following disclaimer in the documentation
+  and/or other materials provided with the distribution.
+
+THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
+AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
+IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE
+DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT HOLDER OR CONTRIBUTORS BE LIABLE
+FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
+DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR
+SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER
+CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY,
+OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
+OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.

vendor/github.com/pkg/errors/README.md

@@ -0,0 +1,52 @@
+# errors [![Travis-CI](https://travis-ci.org/pkg/errors.svg)](https://travis-ci.org/pkg/errors) [![AppVeyor](https://ci.appveyor.com/api/projects/status/b98mptawhudj53ep/branch/master?svg=true)](https://ci.appveyor.com/project/davecheney/errors/branch/master) [![GoDoc](https://godoc.org/github.com/pkg/errors?status.svg)](http://godoc.org/github.com/pkg/errors) [![Report card](https://goreportcard.com/badge/github.com/pkg/errors)](https://goreportcard.com/report/github.com/pkg/errors)
+
+Package errors provides simple error handling primitives.
+
+`go get github.com/pkg/errors`
+
+The traditional error handling idiom in Go is roughly akin to
+```go
+if err != nil {
+        return err
+}
+```
+which applied recursively up the call stack results in error reports without context or debugging information. The errors package allows programmers to add context to the failure path in their code in a way that does not destroy the original value of the error.
+
+## Adding context to an error
+
+The errors.Wrap function returns a new error that adds context to the original error. For example
+```go
+_, err := ioutil.ReadAll(r)
+if err != nil {
+        return errors.Wrap(err, "read failed")
+}
+```
+## Retrieving the cause of an error
+
+Using `errors.Wrap` constructs a stack of errors, adding context to the preceding error. Depending on the nature of the error it may be necessary to reverse the operation of errors.Wrap to retrieve the original error for inspection. Any error value which implements this interface can be inspected by `errors.Cause`.
+```go
+type causer interface {
+        Cause() error
+}
+```
+`errors.Cause` will recursively retrieve the topmost error which does not implement `causer`, which is assumed to be the original cause. For example:
+```go
+switch err := errors.Cause(err).(type) {
+case *MyError:
+        // handle specifically
+default:
+        // unknown error
+}
+```
+
+[Read the package documentation for more information](https://godoc.org/github.com/pkg/errors).
+
+## Contributing
+
+We welcome pull requests, bug fixes and issue reports. With that said, the bar for adding new symbols to this package is intentionally set high.
+
+Before proposing a change, please discuss your change by raising an issue.
+
+## Licence
+
+BSD-2-Clause

vendor/github.com/pkg/errors/appveyor.yml

@@ -0,0 +1,32 @@
+version: build-{build}.{branch}
+
+clone_folder: C:\gopath\src\github.com\pkg\errors
+shallow_clone: true # for startup speed
+
+environment:
+  GOPATH: C:\gopath
+
+platform:
+  - x64
+
+# http://www.appveyor.com/docs/installed-software
+install:
+  # some helpful output for debugging builds
+  - go version
+  - go env
+  # pre-installed MinGW at C:\MinGW is 32bit only
+  # but MSYS2 at C:\msys64 has mingw64
+  - set PATH=C:\msys64\mingw64\bin;%PATH%
+  - gcc --version
+  - g++ --version
+
+build_script:
+  - go install -v ./...
+
+test_script:
+  - set PATH=C:\gopath\bin;%PATH%
+  - go test -v ./...
+
+#artifacts:
+#  - path: '%GOPATH%\bin\*.exe'
+deploy: off

vendor/github.com/pkg/errors/errors.go

@@ -0,0 +1,269 @@
+// Package errors provides simple error handling primitives.
+//
+// The traditional error handling idiom in Go is roughly akin to
+//
+//     if err != nil {
+//             return err
+//     }
+//
+// which applied recursively up the call stack results in error reports
+// without context or debugging information. The errors package allows
+// programmers to add context to the failure path in their code in a way
+// that does not destroy the original value of the error.
+//
+// Adding context to an error
+//
+// The errors.Wrap function returns a new error that adds context to the
+// original error by recording a stack trace at the point Wrap is called,
+// and the supplied message. For example
+//
+//     _, err := ioutil.ReadAll(r)
+//     if err != nil {
+//             return errors.Wrap(err, "read failed")
+//     }
+//
+// If additional control is required the errors.WithStack and errors.WithMessage
+// functions destructure errors.Wrap into its component operations of annotating
+// an error with a stack trace and an a message, respectively.
+//
+// Retrieving the cause of an error
+//
+// Using errors.Wrap constructs a stack of errors, adding context to the
+// preceding error. Depending on the nature of the error it may be necessary
+// to reverse the operation of errors.Wrap to retrieve the original error
+// for inspection. Any error value which implements this interface
+//
+//     type causer interface {
+//             Cause() error
+//     }
+//
+// can be inspected by errors.Cause. errors.Cause will recursively retrieve
+// the topmost error which does not implement causer, which is assumed to be
+// the original cause. For example:
+//
+//     switch err := errors.Cause(err).(type) {
+//     case *MyError:
+//             // handle specifically
+//     default:
+//             // unknown error
+//     }
+//
+// causer interface is not exported by this package, but is considered a part
+// of stable public API.
+//
+// Formatted printing of errors
+//
+// All error values returned from this package implement fmt.Formatter and can
+// be formatted by the fmt package. The following verbs are supported
+//
+//     %s    print the error. If the error has a Cause it will be
+//           printed recursively
+//     %v    see %s
+//     %+v   extended format. Each Frame of the error's StackTrace will
+//           be printed in detail.
+//
+// Retrieving the stack trace of an error or wrapper
+//
+// New, Errorf, Wrap, and Wrapf record a stack trace at the point they are
+// invoked. This information can be retrieved with the following interface.
+//
+//     type stackTracer interface {
+//             StackTrace() errors.StackTrace
+//     }
+//
+// Where errors.StackTrace is defined as
+//
+//     type StackTrace []Frame
+//
+// The Frame type represents a call site in the stack trace. Frame supports
+// the fmt.Formatter interface that can be used for printing information about
+// the stack trace of this error. For example:
+//
+//     if err, ok := err.(stackTracer); ok {
+//             for _, f := range err.StackTrace() {
+//                     fmt.Printf("%+s:%d", f)
+//             }
+//     }
+//
+// stackTracer interface is not exported by this package, but is considered a part
+// of stable public API.
+//
+// See the documentation for Frame.Format for more details.
+package errors
+
+import (
+	"fmt"
+	"io"
+)
+
+// New returns an error with the supplied message.
+// New also records the stack trace at the point it was called.
+func New(message string) error {
+	return &fundamental{
+		msg:   message,
+		stack: callers(),
+	}
+}
+
+// Errorf formats according to a format specifier and returns the string
+// as a value that satisfies error.
+// Errorf also records the stack trace at the point it was called.
+func Errorf(format string, args ...interface{}) error {
+	return &fundamental{
+		msg:   fmt.Sprintf(format, args...),
+		stack: callers(),
+	}
+}
+
+// fundamental is an error that has a message and a stack, but no caller.
+type fundamental struct {
+	msg string
+	*stack
+}
+
+func (f *fundamental) Error() string { return f.msg }
+
+func (f *fundamental) Format(s fmt.State, verb rune) {
+	switch verb {
+	case 'v':
+		if s.Flag('+') {
+			io.WriteString(s, f.msg)
+			f.stack.Format(s, verb)
+			return
+		}
+		fallthrough
+	case 's':
+		io.WriteString(s, f.msg)
+	case 'q':
+		fmt.Fprintf(s, "%q", f.msg)
+	}
+}
+
+// WithStack annotates err with a stack trace at the point WithStack was called.
+// If err is nil, WithStack returns nil.
+func WithStack(err error) error {
+	if err == nil {
+		return nil
+	}
+	return &withStack{
+		err,
+		callers(),
+	}
+}
+
+type withStack struct {
+	error
+	*stack
+}
+
+func (w *withStack) Cause() error { return w.error }
+
+func (w *withStack) Format(s fmt.State, verb rune) {
+	switch verb {
+	case 'v':
+		if s.Flag('+') {
+			fmt.Fprintf(s, "%+v", w.Cause())
+			w.stack.Format(s, verb)
+			return
+		}
+		fallthrough
+	case 's':
+		io.WriteString(s, w.Error())
+	case 'q':
+		fmt.Fprintf(s, "%q", w.Error())
+	}
+}
+
+// Wrap returns an error annotating err with a stack trace
+// at the point Wrap is called, and the supplied message.
+// If err is nil, Wrap returns nil.
+func Wrap(err error, message string) error {
+	if err == nil {
+		return nil
+	}
+	err = &withMessage{
+		cause: err,
+		msg:   message,
+	}
+	return &withStack{
+		err,
+		callers(),
+	}
+}
+
+// Wrapf returns an error annotating err with a stack trace
+// at the point Wrapf is call, and the format specifier.
+// If err is nil, Wrapf returns nil.
+func Wrapf(err error, format string, args ...interface{}) error {
+	if err == nil {
+		return nil
+	}
+	err = &withMessage{
+		cause: err,
+		msg:   fmt.Sprintf(format, args...),
+	}
+	return &withStack{
+		err,
+		callers(),
+	}
+}
+
+// WithMessage annotates err with a new message.
+// If err is nil, WithMessage returns nil.
+func WithMessage(err error, message string) error {
+	if err == nil {
+		return nil
+	}
+	return &withMessage{
+		cause: err,
+		msg:   message,
+	}
+}
+
+type withMessage struct {
+	cause error
+	msg   string
+}
+
+func (w *withMessage) Error() string { return w.msg + ": " + w.cause.Error() }
+func (w *withMessage) Cause() error  { return w.cause }
+
+func (w *withMessage) Format(s fmt.State, verb rune) {
+	switch verb {
+	case 'v':
+		if s.Flag('+') {
+			fmt.Fprintf(s, "%+v\n", w.Cause())
+			io.WriteString(s, w.msg)
+			return
+		}
+		fallthrough
+	case 's', 'q':
+		io.WriteString(s, w.Error())
+	}
+}
+
+// Cause returns the underlying cause of the error, if possible.
+// An error value has a cause if it implements the following
+// interface:
+//
+//     type causer interface {
+//            Cause() error
+//     }
+//
+// If the error does not implement Cause, the original error will
+// be returned. If the error is nil, nil will be returned without further
+// investigation.
+func Cause(err error) error {
+	type causer interface {
+		Cause() error
+	}
+
+	for err != nil {
+		cause, ok := err.(causer)
+		if !ok {
+			break
+		}
+		err = cause.Cause()
+	}
+	return err
+}

vendor/github.com/pkg/errors/stack.go

@@ -0,0 +1,178 @@
+package errors
+
+import (
+	"fmt"
+	"io"
+	"path"
+	"runtime"
+	"strings"
+)
+
+// Frame represents a program counter inside a stack frame.
+type Frame uintptr
+
+// pc returns the program counter for this frame;
+// multiple frames may have the same PC value.
+func (f Frame) pc() uintptr { return uintptr(f) - 1 }
+
+// file returns the full path to the file that contains the
+// function for this Frame's pc.
+func (f Frame) file() string {
+	fn := runtime.FuncForPC(f.pc())
+	if fn == nil {
+		return "unknown"
+	}
+	file, _ := fn.FileLine(f.pc())
+	return file
+}
+
+// line returns the line number of source code of the
+// function for this Frame's pc.
+func (f Frame) line() int {
+	fn := runtime.FuncForPC(f.pc())
+	if fn == nil {
+		return 0
+	}
+	_, line := fn.FileLine(f.pc())
+	return line
+}
+
+// Format formats the frame according to the fmt.Formatter interface.
+//
+//    %s    source file
+//    %d    source line
+//    %n    function name
+//    %v    equivalent to %s:%d
+//
+// Format accepts flags that alter the printing of some verbs, as follows:
+//
+//    %+s   path of source file relative to the compile time GOPATH
+//    %+v   equivalent to %+s:%d
+func (f Frame) Format(s fmt.State, verb rune) {
+	switch verb {
+	case 's':
+		switch {
+		case s.Flag('+'):
+			pc := f.pc()
+			fn := runtime.FuncForPC(pc)
+			if fn == nil {
+				io.WriteString(s, "unknown")
+			} else {
+				file, _ := fn.FileLine(pc)
+				fmt.Fprintf(s, "%s\n\t%s", fn.Name(), file)
+			}
+		default:
+			io.WriteString(s, path.Base(f.file()))
+		}
+	case 'd':
+		fmt.Fprintf(s, "%d", f.line())
+	case 'n':
+		name := runtime.FuncForPC(f.pc()).Name()
+		io.WriteString(s, funcname(name))
+	case 'v':
+		f.Format(s, 's')
+		io.WriteString(s, ":")
+		f.Format(s, 'd')
+	}
+}
+
+// StackTrace is stack of Frames from innermost (newest) to outermost (oldest).
+type StackTrace []Frame
+
+func (st StackTrace) Format(s fmt.State, verb rune) {
+	switch verb {
+	case 'v':
+		switch {
+		case s.Flag('+'):
+			for _, f := range st {
+				fmt.Fprintf(s, "\n%+v", f)
+			}
+		case s.Flag('#'):
+			fmt.Fprintf(s, "%#v", []Frame(st))
+		default:
+			fmt.Fprintf(s, "%v", []Frame(st))
+		}
+	case 's':
+		fmt.Fprintf(s, "%s", []Frame(st))
+	}
+}
+
+// stack represents a stack of program counters.
+type stack []uintptr
+
+func (s *stack) Format(st fmt.State, verb rune) {
+	switch verb {
+	case 'v':
+		switch {
+		case st.Flag('+'):
+			for _, pc := range *s {
+				f := Frame(pc)
+				fmt.Fprintf(st, "\n%+v", f)
+			}
+		}
+	}
+}
+
+func (s *stack) StackTrace() StackTrace {
+	f := make([]Frame, len(*s))
+	for i := 0; i < len(f); i++ {
+		f[i] = Frame((*s)[i])
+	}
+	return f
+}
+
+func callers() *stack {
+	const depth = 32
+	var pcs [depth]uintptr
+	n := runtime.Callers(3, pcs[:])
+	var st stack = pcs[0:n]
+	return &st
+}
+
+// funcname removes the path prefix component of a function's name reported by func.Name().
+func funcname(name string) string {
+	i := strings.LastIndex(name, "/")
+	name = name[i+1:]
+	i = strings.Index(name, ".")
+	return name[i+1:]
+}
+
+func trimGOPATH(name, file string) string {
+	// Here we want to get the source file path relative to the compile time
+	// GOPATH. As of Go 1.6.x there is no direct way to know the compiled
+	// GOPATH at runtime, but we can infer the number of path segments in the
+	// GOPATH. We note that fn.Name() returns the function name qualified by
+	// the import path, which does not include the GOPATH. Thus we can trim
+	// segments from the beginning of the file path until the number of path
+	// separators remaining is one more than the number of path separators in
+	// the function name. For example, given:
+	//
+	//    GOPATH     /home/user
+	//    file       /home/user/src/pkg/sub/file.go
+	//    fn.Name()  pkg/sub.Type.Method
+	//
+	// We want to produce:
+	//
+	//    pkg/sub/file.go
+	//
+	// From this we can easily see that fn.Name() has one less path separator
+	// than our desired output. We count separators from the end of the file
+	// path until it finds two more than in the function name and then move
+	// one character forward to preserve the initial path segment without a
+	// leading separator.
+	const sep = "/"
+	goal := strings.Count(name, sep) + 2
+	i := len(file)
+	for n := 0; n < goal; n++ {
+		i = strings.LastIndex(file[:i], sep)
+		if i == -1 {
+			// not enough separators found, set i so that the slice expression
+			// below leaves file unmodified
+			i = -len(sep)
+			break
+		}
+	}
+	// get back to 0 or trim the leading separator
+	file = file[i+len(sep):]
+	return file
+}

vendor/github.com/sirupsen/logrus/.gitignore

@@ -0,0 +1 @@
+logrus

vendor/github.com/sirupsen/logrus/CHANGELOG.md

@@ -0,0 +1,113 @@
+# 1.0.3
+
+* Replace example files with testable examples
+
+# 1.0.2
+
+* bug: quote non-string values in text formatter (#583)
+* Make (*Logger) SetLevel a public method
+
+# 1.0.1
+
+* bug: fix escaping in text formatter (#575)
+
+# 1.0.0
+
+* Officially changed name to lower-case
+* bug: colors on Windows 10 (#541)
+* bug: fix race in accessing level (#512)
+
+# 0.11.5
+
+* feature: add writer and writerlevel to entry (#372)
+
+# 0.11.4
+
+* bug: fix undefined variable on solaris (#493)
+
+# 0.11.3
+
+* formatter: configure quoting of empty values (#484)
+* formatter: configure quoting character (default is `"`) (#484)
+* bug: fix not importing io correctly in non-linux environments (#481)
+
+# 0.11.2
+
+* bug: fix windows terminal detection (#476)
+
+# 0.11.1
+
+* bug: fix tty detection with custom out (#471)
+
+# 0.11.0
+
+* performance: Use bufferpool to allocate (#370)
+* terminal: terminal detection for app-engine (#343)
+* feature: exit handler (#375)
+
+# 0.10.0
+
+* feature: Add a test hook (#180)
+* feature: `ParseLevel` is now case-insensitive (#326)
+* feature: `FieldLogger` interface that generalizes `Logger` and `Entry` (#308)
+* performance: avoid re-allocations on `WithFields` (#335)
+
+# 0.9.0
+
+* logrus/text_formatter: don't emit empty msg
+* logrus/hooks/airbrake: move out of main repository
+* logrus/hooks/sentry: move out of main repository
+* logrus/hooks/papertrail: move out of main repository
+* logrus/hooks/bugsnag: move out of main repository
+* logrus/core: run tests with `-race`
+* logrus/core: detect TTY based on `stderr`
+* logrus/core: support `WithError` on logger
+* logrus/core: Solaris support
+
+# 0.8.7
+
+* logrus/core: fix possible race (#216)
+* logrus/doc: small typo fixes and doc improvements
+
+
+# 0.8.6
+
+* hooks/raven: allow passing an initialized client
+
+# 0.8.5
+
+* logrus/core: revert #208
+
+# 0.8.4
+
+* formatter/text: fix data race (#218)
+
+# 0.8.3
+
+* logrus/core: fix entry log level (#208)
+* logrus/core: improve performance of text formatter by 40%
+* logrus/core: expose `LevelHooks` type
+* logrus/core: add support for DragonflyBSD and NetBSD
+* formatter/text: print structs more verbosely
+
+# 0.8.2
+
+* logrus: fix more Fatal family functions
+
+# 0.8.1
+
+* logrus: fix not exiting on `Fatalf` and `Fatalln`
+
+# 0.8.0
+
+* logrus: defaults to stderr instead of stdout
+* hooks/sentry: add special field for `*http.Request`
+* formatter/text: ignore Windows for colors
+
+# 0.7.3
+
+* formatter/\*: allow configuration of timestamp layout
+
+# 0.7.2
+
+* formatter/text: Add configuration option for time format (#158)

vendor/github.com/sirupsen/logrus/LICENSE

@@ -0,0 +1,21 @@
+The MIT License (MIT)
+
+Copyright (c) 2014 Simon Eskildsen
+
+Permission is hereby granted, free of charge, to any person obtaining a copy
+of this software and associated documentation files (the "Software"), to deal
+in the Software without restriction, including without limitation the rights
+to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+copies of the Software, and to permit persons to whom the Software is
+furnished to do so, subject to the following conditions:
+
+The above copyright notice and this permission notice shall be included in
+all copies or substantial portions of the Software.
+
+THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
+AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
+THE SOFTWARE.

vendor/github.com/sirupsen/logrus/README.md

@@ -0,0 +1,505 @@
+# Logrus <img src="http://i.imgur.com/hTeVwmJ.png" width="40" height="40" alt=":walrus:" class="emoji" title=":walrus:"/>&nbsp;[![Build Status](https://travis-ci.org/sirupsen/logrus.svg?branch=master)](https://travis-ci.org/sirupsen/logrus)&nbsp;[![GoDoc](https://godoc.org/github.com/sirupsen/logrus?status.svg)](https://godoc.org/github.com/sirupsen/logrus)
+
+Logrus is a structured logger for Go (golang), completely API compatible with
+the standard library logger.
+
+**Seeing weird case-sensitive problems?** It's in the past been possible to
+import Logrus as both upper- and lower-case. Due to the Go package environment,
+this caused issues in the community and we needed a standard. Some environments
+experienced problems with the upper-case variant, so the lower-case was decided.
+Everything using `logrus` will need to use the lower-case:
+`github.com/sirupsen/logrus`. Any package that isn't, should be changed.
+
+To fix Glide, see [these
+comments](https://github.com/sirupsen/logrus/issues/553#issuecomment-306591437).
+For an in-depth explanation of the casing issue, see [this
+comment](https://github.com/sirupsen/logrus/issues/570#issuecomment-313933276).
+
+**Are you interested in assisting in maintaining Logrus?** Currently I have a
+lot of obligations, and I am unable to provide Logrus with the maintainership it
+needs. If you'd like to help, please reach out to me at `simon at author's
+username dot com`.
+
+Nicely color-coded in development (when a TTY is attached, otherwise just
+plain text):
+
+![Colored](http://i.imgur.com/PY7qMwd.png)
+
+With `log.SetFormatter(&log.JSONFormatter{})`, for easy parsing by logstash
+or Splunk:
+
+```json
+{"animal":"walrus","level":"info","msg":"A group of walrus emerges from the
+ocean","size":10,"time":"2014-03-10 19:57:38.562264131 -0400 EDT"}
+
+{"level":"warning","msg":"The group's number increased tremendously!",
+"number":122,"omg":true,"time":"2014-03-10 19:57:38.562471297 -0400 EDT"}
+
+{"animal":"walrus","level":"info","msg":"A giant walrus appears!",
+"size":10,"time":"2014-03-10 19:57:38.562500591 -0400 EDT"}
+
+{"animal":"walrus","level":"info","msg":"Tremendously sized cow enters the ocean.",
+"size":9,"time":"2014-03-10 19:57:38.562527896 -0400 EDT"}
+
+{"level":"fatal","msg":"The ice breaks!","number":100,"omg":true,
+"time":"2014-03-10 19:57:38.562543128 -0400 EDT"}
+```
+
+With the default `log.SetFormatter(&log.TextFormatter{})` when a TTY is not
+attached, the output is compatible with the
+[logfmt](http://godoc.org/github.com/kr/logfmt) format:
+
+```text
+time="2015-03-26T01:27:38-04:00" level=debug msg="Started observing beach" animal=walrus number=8
+time="2015-03-26T01:27:38-04:00" level=info msg="A group of walrus emerges from the ocean" animal=walrus size=10
+time="2015-03-26T01:27:38-04:00" level=warning msg="The group's number increased tremendously!" number=122 omg=true
+time="2015-03-26T01:27:38-04:00" level=debug msg="Temperature changes" temperature=-4
+time="2015-03-26T01:27:38-04:00" level=panic msg="It's over 9000!" animal=orca size=9009
+time="2015-03-26T01:27:38-04:00" level=fatal msg="The ice breaks!" err=&{0x2082280c0 map[animal:orca size:9009] 2015-03-26 01:27:38.441574009 -0400 EDT panic It's over 9000!} number=100 omg=true
+exit status 1
+```
+
+#### Case-sensitivity
+
+The organization's name was changed to lower-case--and this will not be changed
+back. If you are getting import conflicts due to case sensitivity, please use
+the lower-case import: `github.com/sirupsen/logrus`.
+
+#### Example
+
+The simplest way to use Logrus is simply the package-level exported logger:
+
+```go
+package main
+
+import (
+  log "github.com/sirupsen/logrus"
+)
+
+func main() {
+  log.WithFields(log.Fields{
+    "animal": "walrus",
+  }).Info("A walrus appears")
+}
+```
+
+Note that it's completely api-compatible with the stdlib logger, so you can
+replace your `log` imports everywhere with `log "github.com/sirupsen/logrus"`
+and you'll now have the flexibility of Logrus. You can customize it all you
+want:
+
+```go
+package main
+
+import (
+  "os"
+  log "github.com/sirupsen/logrus"
+)
+
+func init() {
+  // Log as JSON instead of the default ASCII formatter.
+  log.SetFormatter(&log.JSONFormatter{})
+
+  // Output to stdout instead of the default stderr
+  // Can be any io.Writer, see below for File example
+  log.SetOutput(os.Stdout)
+
+  // Only log the warning severity or above.
+  log.SetLevel(log.WarnLevel)
+}
+
+func main() {
+  log.WithFields(log.Fields{
+    "animal": "walrus",
+    "size":   10,
+  }).Info("A group of walrus emerges from the ocean")
+
+  log.WithFields(log.Fields{
+    "omg":    true,
+    "number": 122,
+  }).Warn("The group's number increased tremendously!")
+
+  log.WithFields(log.Fields{
+    "omg":    true,
+    "number": 100,
+  }).Fatal("The ice breaks!")
+
+  // A common pattern is to re-use fields between logging statements by re-using
+  // the logrus.Entry returned from WithFields()
+  contextLogger := log.WithFields(log.Fields{
+    "common": "this is a common field",
+    "other": "I also should be logged always",
+  })
+
+  contextLogger.Info("I'll be logged with common and other field")
+  contextLogger.Info("Me too")
+}
+```
+
+For more advanced usage such as logging to multiple locations from the same
+application, you can also create an instance of the `logrus` Logger:
+
+```go
+package main
+
+import (
+  "os"
+  "github.com/sirupsen/logrus"
+)
+
+// Create a new instance of the logger. You can have any number of instances.
+var log = logrus.New()
+
+func main() {
+  // The API for setting attributes is a little different than the package level
+  // exported logger. See Godoc.
+  log.Out = os.Stdout
+
+  // You could set this to any `io.Writer` such as a file
+  // file, err := os.OpenFile("logrus.log", os.O_CREATE|os.O_WRONLY, 0666)
+  // if err == nil {
+  //  log.Out = file
+  // } else {
+  //  log.Info("Failed to log to file, using default stderr")
+  // }
+
+  log.WithFields(logrus.Fields{
+    "animal": "walrus",
+    "size":   10,
+  }).Info("A group of walrus emerges from the ocean")
+}
+```
+
+#### Fields
+
+Logrus encourages careful, structured logging through logging fields instead of
+long, unparseable error messages. For example, instead of: `log.Fatalf("Failed
+to send event %s to topic %s with key %d")`, you should log the much more
+discoverable:
+
+```go
+log.WithFields(log.Fields{
+  "event": event,
+  "topic": topic,
+  "key": key,
+}).Fatal("Failed to send event")
+```
+
+We've found this API forces you to think about logging in a way that produces
+much more useful logging messages. We've been in countless situations where just
+a single added field to a log statement that was already there would've saved us
+hours. The `WithFields` call is optional.
+
+In general, with Logrus using any of the `printf`-family functions should be
+seen as a hint you should add a field, however, you can still use the
+`printf`-family functions with Logrus.
+
+#### Default Fields
+
+Often it's helpful to have fields _always_ attached to log statements in an
+application or parts of one. For example, you may want to always log the
+`request_id` and `user_ip` in the context of a request. Instead of writing
+`log.WithFields(log.Fields{"request_id": request_id, "user_ip": user_ip})` on
+every line, you can create a `logrus.Entry` to pass around instead:
+
+```go
+requestLogger := log.WithFields(log.Fields{"request_id": request_id, "user_ip": user_ip})
+requestLogger.Info("something happened on that request") # will log request_id and user_ip
+requestLogger.Warn("something not great happened")
+```
+
+#### Hooks
+
+You can add hooks for logging levels. For example to send errors to an exception
+tracking service on `Error`, `Fatal` and `Panic`, info to StatsD or log to
+multiple places simultaneously, e.g. syslog.
+
+Logrus comes with [built-in hooks](hooks/). Add those, or your custom hook, in
+`init`:
+
+```go
+import (
+  log "github.com/sirupsen/logrus"
+  "gopkg.in/gemnasium/logrus-airbrake-hook.v2" // the package is named "aibrake"
+  logrus_syslog "github.com/sirupsen/logrus/hooks/syslog"
+  "log/syslog"
+)
+
+func init() {
+
+  // Use the Airbrake hook to report errors that have Error severity or above to
+  // an exception tracker. You can create custom hooks, see the Hooks section.
+  log.AddHook(airbrake.NewHook(123, "xyz", "production"))
+
+  hook, err := logrus_syslog.NewSyslogHook("udp", "localhost:514", syslog.LOG_INFO, "")
+  if err != nil {
+    log.Error("Unable to connect to local syslog daemon")
+  } else {
+    log.AddHook(hook)
+  }
+}
+```
+Note: Syslog hook also support connecting to local syslog (Ex. "/dev/log" or "/var/run/syslog" or "/var/run/log"). For the detail, please check the [syslog hook README](hooks/syslog/README.md).
+
+| Hook  | Description |
+| ----- | ----------- |
+| [Airbrake "legacy"](https://github.com/gemnasium/logrus-airbrake-legacy-hook) | Send errors to an exception tracking service compatible with the Airbrake API V2. Uses [`airbrake-go`](https://github.com/tobi/airbrake-go) behind the scenes. |
+| [Airbrake](https://github.com/gemnasium/logrus-airbrake-hook) | Send errors to the Airbrake API V3. Uses the official [`gobrake`](https://github.com/airbrake/gobrake) behind the scenes. |
+| [Amazon Kinesis](https://github.com/evalphobia/logrus_kinesis) | Hook for logging to [Amazon Kinesis](https://aws.amazon.com/kinesis/) |
+| [Amqp-Hook](https://github.com/vladoatanasov/logrus_amqp) | Hook for logging to Amqp broker (Like RabbitMQ) |
+| [Bugsnag](https://github.com/Shopify/logrus-bugsnag/blob/master/bugsnag.go) | Send errors to the Bugsnag exception tracking service. |
+| [DeferPanic](https://github.com/deferpanic/dp-logrus) | Hook for logging to DeferPanic |
+| [Discordrus](https://github.com/kz/discordrus) | Hook for logging to [Discord](https://discordapp.com/) |
+| [ElasticSearch](https://github.com/sohlich/elogrus) | Hook for logging to ElasticSearch|
+| [Firehose](https://github.com/beaubrewer/logrus_firehose) | Hook for logging to [Amazon Firehose](https://aws.amazon.com/kinesis/firehose/)
+| [Fluentd](https://github.com/evalphobia/logrus_fluent) | Hook for logging to fluentd |
+| [Go-Slack](https://github.com/multiplay/go-slack) | Hook for logging to [Slack](https://slack.com) |
+| [Graylog](https://github.com/gemnasium/logrus-graylog-hook) | Hook for logging to [Graylog](http://graylog2.org/) |
+| [Hiprus](https://github.com/nubo/hiprus) | Send errors to a channel in hipchat. |
+| [Honeybadger](https://github.com/agonzalezro/logrus_honeybadger) | Hook for sending exceptions to Honeybadger |
+| [InfluxDB](https://github.com/Abramovic/logrus_influxdb) | Hook for logging to influxdb |
+| [Influxus](http://github.com/vlad-doru/influxus) | Hook for concurrently logging to [InfluxDB](http://influxdata.com/) |
+| [Journalhook](https://github.com/wercker/journalhook) | Hook for logging to `systemd-journald` |
+| [KafkaLogrus](https://github.com/goibibo/KafkaLogrus) | Hook for logging to kafka |
+| [LFShook](https://github.com/rifflock/lfshook) | Hook for logging to the local filesystem |
+| [Logentries](https://github.com/jcftang/logentriesrus) | Hook for logging to [Logentries](https://logentries.com/) |
+| [Logentrus](https://github.com/puddingfactory/logentrus) | Hook for logging to [Logentries](https://logentries.com/) |
+| [Logmatic.io](https://github.com/logmatic/logmatic-go) | Hook for logging to [Logmatic.io](http://logmatic.io/) |
+| [Logrusly](https://github.com/sebest/logrusly) | Send logs to [Loggly](https://www.loggly.com/) |
+| [Logstash](https://github.com/bshuster-repo/logrus-logstash-hook) | Hook for logging to [Logstash](https://www.elastic.co/products/logstash) |
+| [Mail](https://github.com/zbindenren/logrus_mail) | Hook for sending exceptions via mail |
+| [Mattermost](https://github.com/shuLhan/mattermost-integration/tree/master/hooks/logrus) | Hook for logging to [Mattermost](https://mattermost.com/) |
+| [Mongodb](https://github.com/weekface/mgorus) | Hook for logging to mongodb |
+| [NATS-Hook](https://github.com/rybit/nats_logrus_hook) | Hook for logging to [NATS](https://nats.io) |
+| [Octokit](https://github.com/dorajistyle/logrus-octokit-hook) | Hook for logging to github via octokit |
+| [Papertrail](https://github.com/polds/logrus-papertrail-hook) | Send errors to the [Papertrail](https://papertrailapp.com) hosted logging service via UDP. |
+| [PostgreSQL](https://github.com/gemnasium/logrus-postgresql-hook) | Send logs to [PostgreSQL](http://postgresql.org) |
+| [Pushover](https://github.com/toorop/logrus_pushover) | Send error via [Pushover](https://pushover.net) |
+| [Raygun](https://github.com/squirkle/logrus-raygun-hook) | Hook for logging to [Raygun.io](http://raygun.io/) |
+| [Redis-Hook](https://github.com/rogierlommers/logrus-redis-hook) | Hook for logging to a ELK stack (through Redis) |
+| [Rollrus](https://github.com/heroku/rollrus) | Hook for sending errors to rollbar |
+| [Scribe](https://github.com/sagar8192/logrus-scribe-hook) | Hook for logging to [Scribe](https://github.com/facebookarchive/scribe)|
+| [Sentry](https://github.com/evalphobia/logrus_sentry) | Send errors to the Sentry error logging and aggregation service. |
+| [Slackrus](https://github.com/johntdyer/slackrus) | Hook for Slack chat. |
+| [Stackdriver](https://github.com/knq/sdhook) | Hook for logging to [Google Stackdriver](https://cloud.google.com/logging/) |
+| [Sumorus](https://github.com/doublefree/sumorus) | Hook for logging to [SumoLogic](https://www.sumologic.com/)|
+| [Syslog](https://github.com/sirupsen/logrus/blob/master/hooks/syslog/syslog.go) | Send errors to remote syslog server. Uses standard library `log/syslog` behind the scenes. |
+| [Syslog TLS](https://github.com/shinji62/logrus-syslog-ng) | Send errors to remote syslog server with TLS support. |
+| [TraceView](https://github.com/evalphobia/logrus_appneta) | Hook for logging to [AppNeta TraceView](https://www.appneta.com/products/traceview/) |
+| [Typetalk](https://github.com/dragon3/logrus-typetalk-hook) | Hook for logging to [Typetalk](https://www.typetalk.in/) |
+| [logz.io](https://github.com/ripcurld00d/logrus-logzio-hook) | Hook for logging to [logz.io](https://logz.io), a Log as a Service using Logstash |
+| [SQS-Hook](https://github.com/tsarpaul/logrus_sqs) | Hook for logging to [Amazon Simple Queue Service (SQS)](https://aws.amazon.com/sqs/) |
+
+#### Level logging
+
+Logrus has six logging levels: Debug, Info, Warning, Error, Fatal and Panic.
+
+```go
+log.Debug("Useful debugging information.")
+log.Info("Something noteworthy happened!")
+log.Warn("You should probably take a look at this.")
+log.Error("Something failed but I'm not quitting.")
+// Calls os.Exit(1) after logging
+log.Fatal("Bye.")
+// Calls panic() after logging
+log.Panic("I'm bailing.")
+```
+
+You can set the logging level on a `Logger`, then it will only log entries with
+that severity or anything above it:
+
+```go
+// Will log anything that is info or above (warn, error, fatal, panic). Default.
+log.SetLevel(log.InfoLevel)
+```
+
+It may be useful to set `log.Level = logrus.DebugLevel` in a debug or verbose
+environment if your application has that.
+
+#### Entries
+
+Besides the fields added with `WithField` or `WithFields` some fields are
+automatically added to all logging events:
+
+1. `time`. The timestamp when the entry was created.
+2. `msg`. The logging message passed to `{Info,Warn,Error,Fatal,Panic}` after
+   the `AddFields` call. E.g. `Failed to send event.`
+3. `level`. The logging level. E.g. `info`.
+
+#### Environments
+
+Logrus has no notion of environment.
+
+If you wish for hooks and formatters to only be used in specific environments,
+you should handle that yourself. For example, if your application has a global
+variable `Environment`, which is a string representation of the environment you
+could do:
+
+```go
+import (
+  log "github.com/sirupsen/logrus"
+)
+
+init() {
+  // do something here to set environment depending on an environment variable
+  // or command-line flag
+  if Environment == "production" {
+    log.SetFormatter(&log.JSONFormatter{})
+  } else {
+    // The TextFormatter is default, you don't actually have to do this.
+    log.SetFormatter(&log.TextFormatter{})
+  }
+}
+```
+
+This configuration is how `logrus` was intended to be used, but JSON in
+production is mostly only useful if you do log aggregation with tools like
+Splunk or Logstash.
+
+#### Formatters
+
+The built-in logging formatters are:
+
+* `logrus.TextFormatter`. Logs the event in colors if stdout is a tty, otherwise
+  without colors.
+  * *Note:* to force colored output when there is no TTY, set the `ForceColors`
+    field to `true`.  To force no colored output even if there is a TTY  set the
+    `DisableColors` field to `true`. For Windows, see
+    [github.com/mattn/go-colorable](https://github.com/mattn/go-colorable).
+  * All options are listed in the [generated docs](https://godoc.org/github.com/sirupsen/logrus#TextFormatter).
+* `logrus.JSONFormatter`. Logs fields as JSON.
+  * All options are listed in the [generated docs](https://godoc.org/github.com/sirupsen/logrus#JSONFormatter).
+
+Third party logging formatters:
+
+* [`FluentdFormatter`](https://github.com/joonix/log). Formats entries that can by parsed by Kubernetes and Google Container Engine.
+* [`logstash`](https://github.com/bshuster-repo/logrus-logstash-hook). Logs fields as [Logstash](http://logstash.net) Events.
+* [`prefixed`](https://github.com/x-cray/logrus-prefixed-formatter). Displays log entry source along with alternative layout.
+* [`zalgo`](https://github.com/aybabtme/logzalgo). Invoking the P͉̫o̳̼̊w̖͈̰͎e̬͔̭͂r͚̼̹̲ ̫͓͉̳͈ō̠͕͖̚f̝͍̠ ͕̲̞͖͑Z̖̫̤̫ͪa͉̬͈̗l͖͎g̳̥o̰̥̅!̣͔̲̻͊̄ ̙̘̦̹̦.
+
+You can define your formatter by implementing the `Formatter` interface,
+requiring a `Format` method. `Format` takes an `*Entry`. `entry.Data` is a
+`Fields` type (`map[string]interface{}`) with all your fields as well as the
+default ones (see Entries section above):
+
+```go
+type MyJSONFormatter struct {
+}
+
+log.SetFormatter(new(MyJSONFormatter))
+
+func (f *MyJSONFormatter) Format(entry *Entry) ([]byte, error) {
+  // Note this doesn't include Time, Level and Message which are available on
+  // the Entry. Consult `godoc` on information about those fields or read the
+  // source of the official loggers.
+  serialized, err := json.Marshal(entry.Data)
+    if err != nil {
+      return nil, fmt.Errorf("Failed to marshal fields to JSON, %v", err)
+    }
+  return append(serialized, '\n'), nil
+}
+```
+
+#### Logger as an `io.Writer`
+
+Logrus can be transformed into an `io.Writer`. That writer is the end of an `io.Pipe` and it is your responsibility to close it.
+
+```go
+w := logger.Writer()
+defer w.Close()
+
+srv := http.Server{
+    // create a stdlib log.Logger that writes to
+    // logrus.Logger.
+    ErrorLog: log.New(w, "", 0),
+}
+```
+
+Each line written to that writer will be printed the usual way, using formatters
+and hooks. The level for those entries is `info`.
+
+This means that we can override the standard library logger easily:
+
+```go
+logger := logrus.New()
+logger.Formatter = &logrus.JSONFormatter{}
+
+// Use logrus for standard log output
+// Note that `log` here references stdlib's log
+// Not logrus imported under the name `log`.
+log.SetOutput(logger.Writer())
+```
+
+#### Rotation
+
+Log rotation is not provided with Logrus. Log rotation should be done by an
+external program (like `logrotate(8)`) that can compress and delete old log
+entries. It should not be a feature of the application-level logger.
+
+#### Tools
+
+| Tool | Description |
+| ---- | ----------- |
+|[Logrus Mate](https://github.com/gogap/logrus_mate)|Logrus mate is a tool for Logrus to manage loggers, you can initial logger's level, hook and formatter by config file, the logger will generated with different config at different environment.|
+|[Logrus Viper Helper](https://github.com/heirko/go-contrib/tree/master/logrusHelper)|An Helper around Logrus to wrap with spf13/Viper to load configuration with fangs! And to simplify Logrus configuration use some behavior of [Logrus Mate](https://github.com/gogap/logrus_mate). [sample](https://github.com/heirko/iris-contrib/blob/master/middleware/logrus-logger/example) |
+
+#### Testing
+
+Logrus has a built in facility for asserting the presence of log messages. This is implemented through the `test` hook and provides:
+
+* decorators for existing logger (`test.NewLocal` and `test.NewGlobal`) which basically just add the `test` hook
+* a test logger (`test.NewNullLogger`) that just records log messages (and does not output any):
+
+```go
+import(
+  "github.com/sirupsen/logrus"
+  "github.com/sirupsen/logrus/hooks/test"
+  "github.com/stretchr/testify/assert"
+  "testing"
+)
+
+func TestSomething(t*testing.T){
+  logger, hook := test.NewNullLogger()
+  logger.Error("Helloerror")
+
+  assert.Equal(t, 1, len(hook.Entries))
+  assert.Equal(t, logrus.ErrorLevel, hook.LastEntry().Level)
+  assert.Equal(t, "Helloerror", hook.LastEntry().Message)
+
+  hook.Reset()
+  assert.Nil(t, hook.LastEntry())
+}
+```
+
+#### Fatal handlers
+
+Logrus can register one or more functions that will be called when any `fatal`
+level message is logged. The registered handlers will be executed before
+logrus performs a `os.Exit(1)`. This behavior may be helpful if callers need
+to gracefully shutdown. Unlike a `panic("Something went wrong...")` call which can be intercepted with a deferred `recover` a call to `os.Exit(1)` can not be intercepted.
+
+```
+...
+handler := func() {
+  // gracefully shutdown something...
+}
+logrus.RegisterExitHandler(handler)
+...
+```
+
+#### Thread safety
+
+By default Logger is protected by mutex for concurrent writes, this mutex is invoked when calling hooks and writing logs.
+If you are sure such locking is not needed, you can call logger.SetNoLock() to disable the locking.
+
+Situation when locking is not needed includes:
+
+* You have no hooks registered, or hooks calling is already thread-safe.
+
+* Writing to logger.Out is already thread-safe, for example:
+
+  1) logger.Out is protected by locks.
+
+  2) logger.Out is a os.File handler opened with `O_APPEND` flag, and every write is smaller than 4k. (This allow multi-thread/multi-process writing)
+
+     (Refer to http://www.notthewizard.com/2014/06/17/are-files-appends-really-atomic/)

vendor/github.com/sirupsen/logrus/alt_exit.go

@@ -0,0 +1,64 @@
+package logrus
+
+// The following code was sourced and modified from the
+// https://github.com/tebeka/atexit package governed by the following license:
+//
+// Copyright (c) 2012 Miki Tebeka <miki.tebeka@gmail.com>.
+//
+// Permission is hereby granted, free of charge, to any person obtaining a copy of
+// this software and associated documentation files (the "Software"), to deal in
+// the Software without restriction, including without limitation the rights to
+// use, copy, modify, merge, publish, distribute, sublicense, and/or sell copies of
+// the Software, and to permit persons to whom the Software is furnished to do so,
+// subject to the following conditions:
+//
+// The above copyright notice and this permission notice shall be included in all
+// copies or substantial portions of the Software.
+//
+// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+// IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, FITNESS
+// FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR
+// COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER
+// IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN
+// CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
+
+import (
+	"fmt"
+	"os"
+)
+
+var handlers = []func(){}
+
+func runHandler(handler func()) {
+	defer func() {
+		if err := recover(); err != nil {
+			fmt.Fprintln(os.Stderr, "Error: Logrus exit handler error:", err)
+		}
+	}()
+
+	handler()
+}
+
+func runHandlers() {
+	for _, handler := range handlers {
+		runHandler(handler)
+	}
+}
+
+// Exit runs all the Logrus atexit handlers and then terminates the program using os.Exit(code)
+func Exit(code int) {
+	runHandlers()
+	os.Exit(code)
+}
+
+// RegisterExitHandler adds a Logrus Exit handler, call logrus.Exit to invoke
+// all handlers. The handlers will also be invoked when any Fatal log entry is
+// made.
+//
+// This method is useful when a caller wishes to use logrus to log a fatal
+// message but also needs to gracefully shutdown. An example usecase could be
+// closing database connections, or sending a alert that the application is
+// closing.
+func RegisterExitHandler(handler func()) {
+	handlers = append(handlers, handler)
+}

vendor/github.com/sirupsen/logrus/appveyor.yml

@@ -0,0 +1,14 @@
+version: "{build}"
+platform: x64
+clone_folder: c:\gopath\src\github.com\sirupsen\logrus
+environment:  
+  GOPATH: c:\gopath
+branches:  
+  only:
+    - master
+install:  
+  - set PATH=%GOPATH%\bin;c:\go\bin;%PATH%
+  - go version
+build_script:  
+  - go get -t
+  - go test

vendor/github.com/sirupsen/logrus/doc.go

@@ -0,0 +1,26 @@
+/*
+Package logrus is a structured logger for Go, completely API compatible with the standard library logger.
+
+
+The simplest way to use Logrus is simply the package-level exported logger:
+
+  package main
+
+  import (
+    log "github.com/sirupsen/logrus"
+  )
+
+  func main() {
+    log.WithFields(log.Fields{
+      "animal": "walrus",
+      "number": 1,
+      "size":   10,
+    }).Info("A walrus appears")
+  }
+
+Output:
+  time="2015-09-07T08:48:33Z" level=info msg="A walrus appears" animal=walrus number=1 size=10
+
+For a full guide visit https://github.com/sirupsen/logrus
+*/
+package logrus

vendor/github.com/sirupsen/logrus/entry.go

@@ -0,0 +1,276 @@
+package logrus
+
+import (
+	"bytes"
+	"fmt"
+	"os"
+	"sync"
+	"time"
+)
+
+var bufferPool *sync.Pool
+
+func init() {
+	bufferPool = &sync.Pool{
+		New: func() interface{} {
+			return new(bytes.Buffer)
+		},
+	}
+}
+
+// Defines the key when adding errors using WithError.
+var ErrorKey = "error"
+
+// An entry is the final or intermediate Logrus logging entry. It contains all
+// the fields passed with WithField{,s}. It's finally logged when Debug, Info,
+// Warn, Error, Fatal or Panic is called on it. These objects can be reused and
+// passed around as much as you wish to avoid field duplication.
+type Entry struct {
+	Logger *Logger
+
+	// Contains all the fields set by the user.
+	Data Fields
+
+	// Time at which the log entry was created
+	Time time.Time
+
+	// Level the log entry was logged at: Debug, Info, Warn, Error, Fatal or Panic
+	// This field will be set on entry firing and the value will be equal to the one in Logger struct field.
+	Level Level
+
+	// Message passed to Debug, Info, Warn, Error, Fatal or Panic
+	Message string
+
+	// When formatter is called in entry.log(), an Buffer may be set to entry
+	Buffer *bytes.Buffer
+}
+
+func NewEntry(logger *Logger) *Entry {
+	return &Entry{
+		Logger: logger,
+		// Default is three fields, give a little extra room
+		Data: make(Fields, 5),
+	}
+}
+
+// Returns the string representation from the reader and ultimately the
+// formatter.
+func (entry *Entry) String() (string, error) {
+	serialized, err := entry.Logger.Formatter.Format(entry)
+	if err != nil {
+		return "", err
+	}
+	str := string(serialized)
+	return str, nil
+}
+
+// Add an error as single field (using the key defined in ErrorKey) to the Entry.
+func (entry *Entry) WithError(err error) *Entry {
+	return entry.WithField(ErrorKey, err)
+}
+
+// Add a single field to the Entry.
+func (entry *Entry) WithField(key string, value interface{}) *Entry {
+	return entry.WithFields(Fields{key: value})
+}
+
+// Add a map of fields to the Entry.
+func (entry *Entry) WithFields(fields Fields) *Entry {
+	data := make(Fields, len(entry.Data)+len(fields))
+	for k, v := range entry.Data {
+		data[k] = v
+	}
+	for k, v := range fields {
+		data[k] = v
+	}
+	return &Entry{Logger: entry.Logger, Data: data}
+}
+
+// This function is not declared with a pointer value because otherwise
+// race conditions will occur when using multiple goroutines
+func (entry Entry) log(level Level, msg string) {
+	var buffer *bytes.Buffer
+	entry.Time = time.Now()
+	entry.Level = level
+	entry.Message = msg
+
+	if err := entry.Logger.Hooks.Fire(level, &entry); err != nil {
+		entry.Logger.mu.Lock()
+		fmt.Fprintf(os.Stderr, "Failed to fire hook: %v\n", err)
+		entry.Logger.mu.Unlock()
+	}
+	buffer = bufferPool.Get().(*bytes.Buffer)
+	buffer.Reset()
+	defer bufferPool.Put(buffer)
+	entry.Buffer = buffer
+	serialized, err := entry.Logger.Formatter.Format(&entry)
+	entry.Buffer = nil
+	if err != nil {
+		entry.Logger.mu.Lock()
+		fmt.Fprintf(os.Stderr, "Failed to obtain reader, %v\n", err)
+		entry.Logger.mu.Unlock()
+	} else {
+		entry.Logger.mu.Lock()
+		_, err = entry.Logger.Out.Write(serialized)
+		if err != nil {
+			fmt.Fprintf(os.Stderr, "Failed to write to log, %v\n", err)
+		}
+		entry.Logger.mu.Unlock()
+	}
+
+	// To avoid Entry#log() returning a value that only would make sense for
+	// panic() to use in Entry#Panic(), we avoid the allocation by checking
+	// directly here.
+	if level <= PanicLevel {
+		panic(&entry)
+	}
+}
+
+func (entry *Entry) Debug(args ...interface{}) {
+	if entry.Logger.level() >= DebugLevel {
+		entry.log(DebugLevel, fmt.Sprint(args...))
+	}
+}
+
+func (entry *Entry) Print(args ...interface{}) {
+	entry.Info(args...)
+}
+
+func (entry *Entry) Info(args ...interface{}) {
+	if entry.Logger.level() >= InfoLevel {
+		entry.log(InfoLevel, fmt.Sprint(args...))
+	}
+}
+
+func (entry *Entry) Warn(args ...interface{}) {
+	if entry.Logger.level() >= WarnLevel {
+		entry.log(WarnLevel, fmt.Sprint(args...))
+	}
+}
+
+func (entry *Entry) Warning(args ...interface{}) {
+	entry.Warn(args...)
+}
+
+func (entry *Entry) Error(args ...interface{}) {
+	if entry.Logger.level() >= ErrorLevel {
+		entry.log(ErrorLevel, fmt.Sprint(args...))
+	}
+}
+
+func (entry *Entry) Fatal(args ...interface{}) {
+	if entry.Logger.level() >= FatalLevel {
+		entry.log(FatalLevel, fmt.Sprint(args...))
+	}
+	Exit(1)
+}
+
+func (entry *Entry) Panic(args ...interface{}) {
+	if entry.Logger.level() >= PanicLevel {
+		entry.log(PanicLevel, fmt.Sprint(args...))
+	}
+	panic(fmt.Sprint(args...))
+}
+
+// Entry Printf family functions
+
+func (entry *Entry) Debugf(format string, args ...interface{}) {
+	if entry.Logger.level() >= DebugLevel {
+		entry.Debug(fmt.Sprintf(format, args...))
+	}
+}
+
+func (entry *Entry) Infof(format string, args ...interface{}) {
+	if entry.Logger.level() >= InfoLevel {
+		entry.Info(fmt.Sprintf(format, args...))
+	}
+}
+
+func (entry *Entry) Printf(format string, args ...interface{}) {
+	entry.Infof(format, args...)
+}
+
+func (entry *Entry) Warnf(format string, args ...interface{}) {
+	if entry.Logger.level() >= WarnLevel {
+		entry.Warn(fmt.Sprintf(format, args...))
+	}
+}
+
+func (entry *Entry) Warningf(format string, args ...interface{}) {
+	entry.Warnf(format, args...)
+}
+
+func (entry *Entry) Errorf(format string, args ...interface{}) {
+	if entry.Logger.level() >= ErrorLevel {
+		entry.Error(fmt.Sprintf(format, args...))
+	}
+}
+
+func (entry *Entry) Fatalf(format string, args ...interface{}) {
+	if entry.Logger.level() >= FatalLevel {
+		entry.Fatal(fmt.Sprintf(format, args...))
+	}
+	Exit(1)
+}
+
+func (entry *Entry) Panicf(format string, args ...interface{}) {
+	if entry.Logger.level() >= PanicLevel {
+		entry.Panic(fmt.Sprintf(format, args...))
+	}
+}
+
+// Entry Println family functions
+
+func (entry *Entry) Debugln(args ...interface{}) {
+	if entry.Logger.level() >= DebugLevel {
+		entry.Debug(entry.sprintlnn(args...))
+	}
+}
+
+func (entry *Entry) Infoln(args ...interface{}) {
+	if entry.Logger.level() >= InfoLevel {
+		entry.Info(entry.sprintlnn(args...))
+	}
+}
+
+func (entry *Entry) Println(args ...interface{}) {
+	entry.Infoln(args...)
+}
+
+func (entry *Entry) Warnln(args ...interface{}) {
+	if entry.Logger.level() >= WarnLevel {
+		entry.Warn(entry.sprintlnn(args...))
+	}
+}
+
+func (entry *Entry) Warningln(args ...interface{}) {
+	entry.Warnln(args...)
+}
+
+func (entry *Entry) Errorln(args ...interface{}) {
+	if entry.Logger.level() >= ErrorLevel {
+		entry.Error(entry.sprintlnn(args...))
+	}
+}
+
+func (entry *Entry) Fatalln(args ...interface{}) {
+	if entry.Logger.level() >= FatalLevel {
+		entry.Fatal(entry.sprintlnn(args...))
+	}
+	Exit(1)
+}
+
+func (entry *Entry) Panicln(args ...interface{}) {
+	if entry.Logger.level() >= PanicLevel {
+		entry.Panic(entry.sprintlnn(args...))
+	}
+}
+
+// Sprintlnn => Sprint no newline. This is to get the behavior of how
+// fmt.Sprintln where spaces are always added between operands, regardless of
+// their type. Instead of vendoring the Sprintln implementation to spare a
+// string allocation, we do the simplest thing.
+func (entry *Entry) sprintlnn(args ...interface{}) string {
+	msg := fmt.Sprintln(args...)
+	return msg[:len(msg)-1]
+}

vendor/github.com/sirupsen/logrus/exported.go

@@ -0,0 +1,193 @@
+package logrus
+
+import (
+	"io"
+)
+
+var (
+	// std is the name of the standard logger in stdlib `log`
+	std = New()
+)
+
+func StandardLogger() *Logger {
+	return std
+}
+
+// SetOutput sets the standard logger output.
+func SetOutput(out io.Writer) {
+	std.mu.Lock()
+	defer std.mu.Unlock()
+	std.Out = out
+}
+
+// SetFormatter sets the standard logger formatter.
+func SetFormatter(formatter Formatter) {
+	std.mu.Lock()
+	defer std.mu.Unlock()
+	std.Formatter = formatter
+}
+
+// SetLevel sets the standard logger level.
+func SetLevel(level Level) {
+	std.mu.Lock()
+	defer std.mu.Unlock()
+	std.SetLevel(level)
+}
+
+// GetLevel returns the standard logger level.
+func GetLevel() Level {
+	std.mu.Lock()
+	defer std.mu.Unlock()
+	return std.level()
+}
+
+// AddHook adds a hook to the standard logger hooks.
+func AddHook(hook Hook) {
+	std.mu.Lock()
+	defer std.mu.Unlock()
+	std.Hooks.Add(hook)
+}
+
+// WithError creates an entry from the standard logger and adds an error to it, using the value defined in ErrorKey as key.
+func WithError(err error) *Entry {
+	return std.WithField(ErrorKey, err)
+}
+
+// WithField creates an entry from the standard logger and adds a field to
+// it. If you want multiple fields, use `WithFields`.
+//
+// Note that it doesn't log until you call Debug, Print, Info, Warn, Fatal
+// or Panic on the Entry it returns.
+func WithField(key string, value interface{}) *Entry {
+	return std.WithField(key, value)
+}
+
+// WithFields creates an entry from the standard logger and adds multiple
+// fields to it. This is simply a helper for `WithField`, invoking it
+// once for each field.
+//
+// Note that it doesn't log until you call Debug, Print, Info, Warn, Fatal
+// or Panic on the Entry it returns.
+func WithFields(fields Fields) *Entry {
+	return std.WithFields(fields)
+}
+
+// Debug logs a message at level Debug on the standard logger.
+func Debug(args ...interface{}) {
+	std.Debug(args...)
+}
+
+// Print logs a message at level Info on the standard logger.
+func Print(args ...interface{}) {
+	std.Print(args...)
+}
+
+// Info logs a message at level Info on the standard logger.
+func Info(args ...interface{}) {
+	std.Info(args...)
+}
+
+// Warn logs a message at level Warn on the standard logger.
+func Warn(args ...interface{}) {
+	std.Warn(args...)
+}
+
+// Warning logs a message at level Warn on the standard logger.
+func Warning(args ...interface{}) {
+	std.Warning(args...)
+}
+
+// Error logs a message at level Error on the standard logger.
+func Error(args ...interface{}) {
+	std.Error(args...)
+}
+
+// Panic logs a message at level Panic on the standard logger.
+func Panic(args ...interface{}) {
+	std.Panic(args...)
+}
+
+// Fatal logs a message at level Fatal on the standard logger.
+func Fatal(args ...interface{}) {
+	std.Fatal(args...)
+}
+
+// Debugf logs a message at level Debug on the standard logger.
+func Debugf(format string, args ...interface{}) {
+	std.Debugf(format, args...)
+}
+
+// Printf logs a message at level Info on the standard logger.
+func Printf(format string, args ...interface{}) {
+	std.Printf(format, args...)
+}
+
+// Infof logs a message at level Info on the standard logger.
+func Infof(format string, args ...interface{}) {
+	std.Infof(format, args...)
+}
+
+// Warnf logs a message at level Warn on the standard logger.
+func Warnf(format string, args ...interface{}) {
+	std.Warnf(format, args...)
+}
+
+// Warningf logs a message at level Warn on the standard logger.
+func Warningf(format string, args ...interface{}) {
+	std.Warningf(format, args...)
+}
+
+// Errorf logs a message at level Error on the standard logger.
+func Errorf(format string, args ...interface{}) {
+	std.Errorf(format, args...)
+}
+
+// Panicf logs a message at level Panic on the standard logger.
+func Panicf(format string, args ...interface{}) {
+	std.Panicf(format, args...)
+}
+
+// Fatalf logs a message at level Fatal on the standard logger.
+func Fatalf(format string, args ...interface{}) {
+	std.Fatalf(format, args...)
+}
+
+// Debugln logs a message at level Debug on the standard logger.
+func Debugln(args ...interface{}) {
+	std.Debugln(args...)
+}
+
+// Println logs a message at level Info on the standard logger.
+func Println(args ...interface{}) {
+	std.Println(args...)
+}
+
+// Infoln logs a message at level Info on the standard logger.
+func Infoln(args ...interface{}) {
+	std.Infoln(args...)
+}
+
+// Warnln logs a message at level Warn on the standard logger.
+func Warnln(args ...interface{}) {
+	std.Warnln(args...)
+}
+
+// Warningln logs a message at level Warn on the standard logger.
+func Warningln(args ...interface{}) {
+	std.Warningln(args...)
+}
+
+// Errorln logs a message at level Error on the standard logger.
+func Errorln(args ...interface{}) {
+	std.Errorln(args...)
+}
+
+// Panicln logs a message at level Panic on the standard logger.
+func Panicln(args ...interface{}) {
+	std.Panicln(args...)
+}
+
+// Fatalln logs a message at level Fatal on the standard logger.
+func Fatalln(args ...interface{}) {
+	std.Fatalln(args...)
+}

vendor/github.com/sirupsen/logrus/formatter.go

@@ -0,0 +1,45 @@
+package logrus
+
+import "time"
+
+const defaultTimestampFormat = time.RFC3339
+
+// The Formatter interface is used to implement a custom Formatter. It takes an
+// `Entry`. It exposes all the fields, including the default ones:
+//
+// * `entry.Data["msg"]`. The message passed from Info, Warn, Error ..
+// * `entry.Data["time"]`. The timestamp.
+// * `entry.Data["level"]. The level the entry was logged at.
+//
+// Any additional fields added with `WithField` or `WithFields` are also in
+// `entry.Data`. Format is expected to return an array of bytes which are then
+// logged to `logger.Out`.
+type Formatter interface {
+	Format(*Entry) ([]byte, error)
+}
+
+// This is to not silently overwrite `time`, `msg` and `level` fields when
+// dumping it. If this code wasn't there doing:
+//
+//  logrus.WithField("level", 1).Info("hello")
+//
+// Would just silently drop the user provided level. Instead with this code
+// it'll logged as:
+//
+//  {"level": "info", "fields.level": 1, "msg": "hello", "time": "..."}
+//
+// It's not exported because it's still using Data in an opinionated way. It's to
+// avoid code duplication between the two default formatters.
+func prefixFieldClashes(data Fields) {
+	if t, ok := data["time"]; ok {
+		data["fields.time"] = t
+	}
+
+	if m, ok := data["msg"]; ok {
+		data["fields.msg"] = m
+	}
+
+	if l, ok := data["level"]; ok {
+		data["fields.level"] = l
+	}
+}

vendor/github.com/sirupsen/logrus/hooks.go

@@ -0,0 +1,34 @@
+package logrus
+
+// A hook to be fired when logging on the logging levels returned from
+// `Levels()` on your implementation of the interface. Note that this is not
+// fired in a goroutine or a channel with workers, you should handle such
+// functionality yourself if your call is non-blocking and you don't wish for
+// the logging calls for levels returned from `Levels()` to block.
+type Hook interface {
+	Levels() []Level
+	Fire(*Entry) error
+}
+
+// Internal type for storing the hooks on a logger instance.
+type LevelHooks map[Level][]Hook
+
+// Add a hook to an instance of logger. This is called with
+// `log.Hooks.Add(new(MyHook))` where `MyHook` implements the `Hook` interface.
+func (hooks LevelHooks) Add(hook Hook) {
+	for _, level := range hook.Levels() {
+		hooks[level] = append(hooks[level], hook)
+	}
+}
+
+// Fire all the hooks for the passed level. Used by `entry.log` to fire
+// appropriate hooks for a log entry.
+func (hooks LevelHooks) Fire(level Level, entry *Entry) error {
+	for _, hook := range hooks[level] {
+		if err := hook.Fire(entry); err != nil {
+			return err
+		}
+	}
+
+	return nil
+}

vendor/github.com/sirupsen/logrus/hooks/test/test.go

@@ -0,0 +1,95 @@
+// The Test package is used for testing logrus. It is here for backwards
+// compatibility from when logrus' organization was upper-case. Please use
+// lower-case logrus and the `null` package instead of this one.
+package test
+
+import (
+	"io/ioutil"
+	"sync"
+
+	"github.com/sirupsen/logrus"
+)
+
+// Hook is a hook designed for dealing with logs in test scenarios.
+type Hook struct {
+	// Entries is an array of all entries that have been received by this hook.
+	// For safe access, use the AllEntries() method, rather than reading this
+	// value directly.
+	Entries []*logrus.Entry
+	mu      sync.RWMutex
+}
+
+// NewGlobal installs a test hook for the global logger.
+func NewGlobal() *Hook {
+
+	hook := new(Hook)
+	logrus.AddHook(hook)
+
+	return hook
+
+}
+
+// NewLocal installs a test hook for a given local logger.
+func NewLocal(logger *logrus.Logger) *Hook {
+
+	hook := new(Hook)
+	logger.Hooks.Add(hook)
+
+	return hook
+
+}
+
+// NewNullLogger creates a discarding logger and installs the test hook.
+func NewNullLogger() (*logrus.Logger, *Hook) {
+
+	logger := logrus.New()
+	logger.Out = ioutil.Discard
+
+	return logger, NewLocal(logger)
+
+}
+
+func (t *Hook) Fire(e *logrus.Entry) error {
+	t.mu.Lock()
+	defer t.mu.Unlock()
+	t.Entries = append(t.Entries, e)
+	return nil
+}
+
+func (t *Hook) Levels() []logrus.Level {
+	return logrus.AllLevels
+}
+
+// LastEntry returns the last entry that was logged or nil.
+func (t *Hook) LastEntry() *logrus.Entry {
+	t.mu.RLock()
+	defer t.mu.RUnlock()
+	i := len(t.Entries) - 1
+	if i < 0 {
+		return nil
+	}
+	// Make a copy, for safety
+	e := *t.Entries[i]
+	return &e
+}
+
+// AllEntries returns all entries that were logged.
+func (t *Hook) AllEntries() []*logrus.Entry {
+	t.mu.RLock()
+	defer t.mu.RUnlock()
+	// Make a copy so the returned value won't race with future log requests
+	entries := make([]*logrus.Entry, len(t.Entries))
+	for i, entry := range t.Entries {
+		// Make a copy, for safety
+		e := *entry
+		entries[i] = &e
+	}
+	return entries
+}
+
+// Reset removes all Entries from this test hook.
+func (t *Hook) Reset() {
+	t.mu.Lock()
+	defer t.mu.Unlock()
+	t.Entries = make([]*logrus.Entry, 0)
+}

vendor/github.com/sirupsen/logrus/json_formatter.go

@@ -0,0 +1,79 @@
+package logrus
+
+import (
+	"encoding/json"
+	"fmt"
+)
+
+type fieldKey string
+
+// FieldMap allows customization of the key names for default fields.
+type FieldMap map[fieldKey]string
+
+// Default key names for the default fields
+const (
+	FieldKeyMsg   = "msg"
+	FieldKeyLevel = "level"
+	FieldKeyTime  = "time"
+)
+
+func (f FieldMap) resolve(key fieldKey) string {
+	if k, ok := f[key]; ok {
+		return k
+	}
+
+	return string(key)
+}
+
+// JSONFormatter formats logs into parsable json
+type JSONFormatter struct {
+	// TimestampFormat sets the format used for marshaling timestamps.
+	TimestampFormat string
+
+	// DisableTimestamp allows disabling automatic timestamps in output
+	DisableTimestamp bool
+
+	// FieldMap allows users to customize the names of keys for default fields.
+	// As an example:
+	// formatter := &JSONFormatter{
+	//   	FieldMap: FieldMap{
+	// 		 FieldKeyTime: "@timestamp",
+	// 		 FieldKeyLevel: "@level",
+	// 		 FieldKeyMsg: "@message",
+	//    },
+	// }
+	FieldMap FieldMap
+}
+
+// Format renders a single log entry
+func (f *JSONFormatter) Format(entry *Entry) ([]byte, error) {
+	data := make(Fields, len(entry.Data)+3)
+	for k, v := range entry.Data {
+		switch v := v.(type) {
+		case error:
+			// Otherwise errors are ignored by `encoding/json`
+			// https://github.com/sirupsen/logrus/issues/137
+			data[k] = v.Error()
+		default:
+			data[k] = v
+		}
+	}
+	prefixFieldClashes(data)
+
+	timestampFormat := f.TimestampFormat
+	if timestampFormat == "" {
+		timestampFormat = defaultTimestampFormat
+	}
+
+	if !f.DisableTimestamp {
+		data[f.FieldMap.resolve(FieldKeyTime)] = entry.Time.Format(timestampFormat)
+	}
+	data[f.FieldMap.resolve(FieldKeyMsg)] = entry.Message
+	data[f.FieldMap.resolve(FieldKeyLevel)] = entry.Level.String()
+
+	serialized, err := json.Marshal(data)
+	if err != nil {
+		return nil, fmt.Errorf("Failed to marshal fields to JSON, %v", err)
+	}
+	return append(serialized, '\n'), nil
+}

vendor/github.com/sirupsen/logrus/logger.go

@@ -0,0 +1,317 @@
+package logrus
+
+import (
+	"io"
+	"os"
+	"sync"
+	"sync/atomic"
+)
+
+type Logger struct {
+	// The logs are `io.Copy`'d to this in a mutex. It's common to set this to a
+	// file, or leave it default which is `os.Stderr`. You can also set this to
+	// something more adventorous, such as logging to Kafka.
+	Out io.Writer
+	// Hooks for the logger instance. These allow firing events based on logging
+	// levels and log entries. For example, to send errors to an error tracking
+	// service, log to StatsD or dump the core on fatal errors.
+	Hooks LevelHooks
+	// All log entries pass through the formatter before logged to Out. The
+	// included formatters are `TextFormatter` and `JSONFormatter` for which
+	// TextFormatter is the default. In development (when a TTY is attached) it
+	// logs with colors, but to a file it wouldn't. You can easily implement your
+	// own that implements the `Formatter` interface, see the `README` or included
+	// formatters for examples.
+	Formatter Formatter
+	// The logging level the logger should log at. This is typically (and defaults
+	// to) `logrus.Info`, which allows Info(), Warn(), Error() and Fatal() to be
+	// logged.
+	Level Level
+	// Used to sync writing to the log. Locking is enabled by Default
+	mu MutexWrap
+	// Reusable empty entry
+	entryPool sync.Pool
+}
+
+type MutexWrap struct {
+	lock     sync.Mutex
+	disabled bool
+}
+
+func (mw *MutexWrap) Lock() {
+	if !mw.disabled {
+		mw.lock.Lock()
+	}
+}
+
+func (mw *MutexWrap) Unlock() {
+	if !mw.disabled {
+		mw.lock.Unlock()
+	}
+}
+
+func (mw *MutexWrap) Disable() {
+	mw.disabled = true
+}
+
+// Creates a new logger. Configuration should be set by changing `Formatter`,
+// `Out` and `Hooks` directly on the default logger instance. You can also just
+// instantiate your own:
+//
+//    var log = &Logger{
+//      Out: os.Stderr,
+//      Formatter: new(JSONFormatter),
+//      Hooks: make(LevelHooks),
+//      Level: logrus.DebugLevel,
+//    }
+//
+// It's recommended to make this a global instance called `log`.
+func New() *Logger {
+	return &Logger{
+		Out:       os.Stderr,
+		Formatter: new(TextFormatter),
+		Hooks:     make(LevelHooks),
+		Level:     InfoLevel,
+	}
+}
+
+func (logger *Logger) newEntry() *Entry {
+	entry, ok := logger.entryPool.Get().(*Entry)
+	if ok {
+		return entry
+	}
+	return NewEntry(logger)
+}
+
+func (logger *Logger) releaseEntry(entry *Entry) {
+	logger.entryPool.Put(entry)
+}
+
+// Adds a field to the log entry, note that it doesn't log until you call
+// Debug, Print, Info, Warn, Fatal or Panic. It only creates a log entry.
+// If you want multiple fields, use `WithFields`.
+func (logger *Logger) WithField(key string, value interface{}) *Entry {
+	entry := logger.newEntry()
+	defer logger.releaseEntry(entry)
+	return entry.WithField(key, value)
+}
+
+// Adds a struct of fields to the log entry. All it does is call `WithField` for
+// each `Field`.
+func (logger *Logger) WithFields(fields Fields) *Entry {
+	entry := logger.newEntry()
+	defer logger.releaseEntry(entry)
+	return entry.WithFields(fields)
+}
+
+// Add an error as single field to the log entry.  All it does is call
+// `WithError` for the given `error`.
+func (logger *Logger) WithError(err error) *Entry {
+	entry := logger.newEntry()
+	defer logger.releaseEntry(entry)
+	return entry.WithError(err)
+}
+
+func (logger *Logger) Debugf(format string, args ...interface{}) {
+	if logger.level() >= DebugLevel {
+		entry := logger.newEntry()
+		entry.Debugf(format, args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+func (logger *Logger) Infof(format string, args ...interface{}) {
+	if logger.level() >= InfoLevel {
+		entry := logger.newEntry()
+		entry.Infof(format, args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+func (logger *Logger) Printf(format string, args ...interface{}) {
+	entry := logger.newEntry()
+	entry.Printf(format, args...)
+	logger.releaseEntry(entry)
+}
+
+func (logger *Logger) Warnf(format string, args ...interface{}) {
+	if logger.level() >= WarnLevel {
+		entry := logger.newEntry()
+		entry.Warnf(format, args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+func (logger *Logger) Warningf(format string, args ...interface{}) {
+	if logger.level() >= WarnLevel {
+		entry := logger.newEntry()
+		entry.Warnf(format, args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+func (logger *Logger) Errorf(format string, args ...interface{}) {
+	if logger.level() >= ErrorLevel {
+		entry := logger.newEntry()
+		entry.Errorf(format, args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+func (logger *Logger) Fatalf(format string, args ...interface{}) {
+	if logger.level() >= FatalLevel {
+		entry := logger.newEntry()
+		entry.Fatalf(format, args...)
+		logger.releaseEntry(entry)
+	}
+	Exit(1)
+}
+
+func (logger *Logger) Panicf(format string, args ...interface{}) {
+	if logger.level() >= PanicLevel {
+		entry := logger.newEntry()
+		entry.Panicf(format, args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+func (logger *Logger) Debug(args ...interface{}) {
+	if logger.level() >= DebugLevel {
+		entry := logger.newEntry()
+		entry.Debug(args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+func (logger *Logger) Info(args ...interface{}) {
+	if logger.level() >= InfoLevel {
+		entry := logger.newEntry()
+		entry.Info(args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+func (logger *Logger) Print(args ...interface{}) {
+	entry := logger.newEntry()
+	entry.Info(args...)
+	logger.releaseEntry(entry)
+}
+
+func (logger *Logger) Warn(args ...interface{}) {
+	if logger.level() >= WarnLevel {
+		entry := logger.newEntry()
+		entry.Warn(args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+func (logger *Logger) Warning(args ...interface{}) {
+	if logger.level() >= WarnLevel {
+		entry := logger.newEntry()
+		entry.Warn(args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+func (logger *Logger) Error(args ...interface{}) {
+	if logger.level() >= ErrorLevel {
+		entry := logger.newEntry()
+		entry.Error(args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+func (logger *Logger) Fatal(args ...interface{}) {
+	if logger.level() >= FatalLevel {
+		entry := logger.newEntry()
+		entry.Fatal(args...)
+		logger.releaseEntry(entry)
+	}
+	Exit(1)
+}
+
+func (logger *Logger) Panic(args ...interface{}) {
+	if logger.level() >= PanicLevel {
+		entry := logger.newEntry()
+		entry.Panic(args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+func (logger *Logger) Debugln(args ...interface{}) {
+	if logger.level() >= DebugLevel {
+		entry := logger.newEntry()
+		entry.Debugln(args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+func (logger *Logger) Infoln(args ...interface{}) {
+	if logger.level() >= InfoLevel {
+		entry := logger.newEntry()
+		entry.Infoln(args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+func (logger *Logger) Println(args ...interface{}) {
+	entry := logger.newEntry()
+	entry.Println(args...)
+	logger.releaseEntry(entry)
+}
+
+func (logger *Logger) Warnln(args ...interface{}) {
+	if logger.level() >= WarnLevel {
+		entry := logger.newEntry()
+		entry.Warnln(args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+func (logger *Logger) Warningln(args ...interface{}) {
+	if logger.level() >= WarnLevel {
+		entry := logger.newEntry()
+		entry.Warnln(args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+func (logger *Logger) Errorln(args ...interface{}) {
+	if logger.level() >= ErrorLevel {
+		entry := logger.newEntry()
+		entry.Errorln(args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+func (logger *Logger) Fatalln(args ...interface{}) {
+	if logger.level() >= FatalLevel {
+		entry := logger.newEntry()
+		entry.Fatalln(args...)
+		logger.releaseEntry(entry)
+	}
+	Exit(1)
+}
+
+func (logger *Logger) Panicln(args ...interface{}) {
+	if logger.level() >= PanicLevel {
+		entry := logger.newEntry()
+		entry.Panicln(args...)
+		logger.releaseEntry(entry)
+	}
+}
+
+//When file is opened with appending mode, it's safe to
+//write concurrently to a file (within 4k message on Linux).
+//In these cases user can choose to disable the lock.
+func (logger *Logger) SetNoLock() {
+	logger.mu.Disable()
+}
+
+func (logger *Logger) level() Level {
+	return Level(atomic.LoadUint32((*uint32)(&logger.Level)))
+}
+
+func (logger *Logger) SetLevel(level Level) {
+	atomic.StoreUint32((*uint32)(&logger.Level), uint32(level))
+}

vendor/github.com/sirupsen/logrus/logrus.go

@@ -0,0 +1,143 @@
+package logrus
+
+import (
+	"fmt"
+	"log"
+	"strings"
+)
+
+// Fields type, used to pass to `WithFields`.
+type Fields map[string]interface{}
+
+// Level type
+type Level uint32
+
+// Convert the Level to a string. E.g. PanicLevel becomes "panic".
+func (level Level) String() string {
+	switch level {
+	case DebugLevel:
+		return "debug"
+	case InfoLevel:
+		return "info"
+	case WarnLevel:
+		return "warning"
+	case ErrorLevel:
+		return "error"
+	case FatalLevel:
+		return "fatal"
+	case PanicLevel:
+		return "panic"
+	}
+
+	return "unknown"
+}
+
+// ParseLevel takes a string level and returns the Logrus log level constant.
+func ParseLevel(lvl string) (Level, error) {
+	switch strings.ToLower(lvl) {
+	case "panic":
+		return PanicLevel, nil
+	case "fatal":
+		return FatalLevel, nil
+	case "error":
+		return ErrorLevel, nil
+	case "warn", "warning":
+		return WarnLevel, nil
+	case "info":
+		return InfoLevel, nil
+	case "debug":
+		return DebugLevel, nil
+	}
+
+	var l Level
+	return l, fmt.Errorf("not a valid logrus Level: %q", lvl)
+}
+
+// A constant exposing all logging levels
+var AllLevels = []Level{
+	PanicLevel,
+	FatalLevel,
+	ErrorLevel,
+	WarnLevel,
+	InfoLevel,
+	DebugLevel,
+}
+
+// These are the different logging levels. You can set the logging level to log
+// on your instance of logger, obtained with `logrus.New()`.
+const (
+	// PanicLevel level, highest level of severity. Logs and then calls panic with the
+	// message passed to Debug, Info, ...
+	PanicLevel Level = iota
+	// FatalLevel level. Logs and then calls `os.Exit(1)`. It will exit even if the
+	// logging level is set to Panic.
+	FatalLevel
+	// ErrorLevel level. Logs. Used for errors that should definitely be noted.
+	// Commonly used for hooks to send errors to an error tracking service.
+	ErrorLevel
+	// WarnLevel level. Non-critical entries that deserve eyes.
+	WarnLevel
+	// InfoLevel level. General operational entries about what's going on inside the
+	// application.
+	InfoLevel
+	// DebugLevel level. Usually only enabled when debugging. Very verbose logging.
+	DebugLevel
+)
+
+// Won't compile if StdLogger can't be realized by a log.Logger
+var (
+	_ StdLogger = &log.Logger{}
+	_ StdLogger = &Entry{}
+	_ StdLogger = &Logger{}
+)
+
+// StdLogger is what your logrus-enabled library should take, that way
+// it'll accept a stdlib logger and a logrus logger. There's no standard
+// interface, this is the closest we get, unfortunately.
+type StdLogger interface {
+	Print(...interface{})
+	Printf(string, ...interface{})
+	Println(...interface{})
+
+	Fatal(...interface{})
+	Fatalf(string, ...interface{})
+	Fatalln(...interface{})
+
+	Panic(...interface{})
+	Panicf(string, ...interface{})
+	Panicln(...interface{})
+}
+
+// The FieldLogger interface generalizes the Entry and Logger types
+type FieldLogger interface {
+	WithField(key string, value interface{}) *Entry
+	WithFields(fields Fields) *Entry
+	WithError(err error) *Entry
+
+	Debugf(format string, args ...interface{})
+	Infof(format string, args ...interface{})
+	Printf(format string, args ...interface{})
+	Warnf(format string, args ...interface{})
+	Warningf(format string, args ...interface{})
+	Errorf(format string, args ...interface{})
+	Fatalf(format string, args ...interface{})
+	Panicf(format string, args ...interface{})
+
+	Debug(args ...interface{})
+	Info(args ...interface{})
+	Print(args ...interface{})
+	Warn(args ...interface{})
+	Warning(args ...interface{})
+	Error(args ...interface{})
+	Fatal(args ...interface{})
+	Panic(args ...interface{})
+
+	Debugln(args ...interface{})
+	Infoln(args ...interface{})
+	Println(args ...interface{})
+	Warnln(args ...interface{})
+	Warningln(args ...interface{})
+	Errorln(args ...interface{})
+	Fatalln(args ...interface{})
+	Panicln(args ...interface{})
+}

vendor/github.com/sirupsen/logrus/terminal_bsd.go

@@ -0,0 +1,10 @@
+// +build darwin freebsd openbsd netbsd dragonfly
+// +build !appengine
+
+package logrus
+
+import "golang.org/x/sys/unix"
+
+const ioctlReadTermios = unix.TIOCGETA
+
+type Termios unix.Termios

vendor/github.com/sirupsen/logrus/terminal_linux.go

@@ -0,0 +1,14 @@
+// Based on ssh/terminal:
+// Copyright 2013 The Go Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style
+// license that can be found in the LICENSE file.
+
+// +build !appengine
+
+package logrus
+
+import "golang.org/x/sys/unix"
+
+const ioctlReadTermios = unix.TCGETS
+
+type Termios unix.Termios

vendor/github.com/sirupsen/logrus/text_formatter.go

@@ -0,0 +1,191 @@
+package logrus
+
+import (
+	"bytes"
+	"fmt"
+	"io"
+	"os"
+	"sort"
+	"strings"
+	"sync"
+	"time"
+
+	"golang.org/x/crypto/ssh/terminal"
+)
+
+const (
+	nocolor = 0
+	red     = 31
+	green   = 32
+	yellow  = 33
+	blue    = 36
+	gray    = 37
+)
+
+var (
+	baseTimestamp time.Time
+)
+
+func init() {
+	baseTimestamp = time.Now()
+}
+
+// TextFormatter formats logs into text
+type TextFormatter struct {
+	// Set to true to bypass checking for a TTY before outputting colors.
+	ForceColors bool
+
+	// Force disabling colors.
+	DisableColors bool
+
+	// Disable timestamp logging. useful when output is redirected to logging
+	// system that already adds timestamps.
+	DisableTimestamp bool
+
+	// Enable logging the full timestamp when a TTY is attached instead of just
+	// the time passed since beginning of execution.
+	FullTimestamp bool
+
+	// TimestampFormat to use for display when a full timestamp is printed
+	TimestampFormat string
+
+	// The fields are sorted by default for a consistent output. For applications
+	// that log extremely frequently and don't use the JSON formatter this may not
+	// be desired.
+	DisableSorting bool
+
+	// QuoteEmptyFields will wrap empty fields in quotes if true
+	QuoteEmptyFields bool
+
+	// Whether the logger's out is to a terminal
+	isTerminal bool
+
+	sync.Once
+}
+
+func (f *TextFormatter) init(entry *Entry) {
+	if entry.Logger != nil {
+		f.isTerminal = f.checkIfTerminal(entry.Logger.Out)
+	}
+}
+
+func (f *TextFormatter) checkIfTerminal(w io.Writer) bool {
+	switch v := w.(type) {
+	case *os.File:
+		return terminal.IsTerminal(int(v.Fd()))
+	default:
+		return false
+	}
+}
+
+// Format renders a single log entry
+func (f *TextFormatter) Format(entry *Entry) ([]byte, error) {
+	var b *bytes.Buffer
+	keys := make([]string, 0, len(entry.Data))
+	for k := range entry.Data {
+		keys = append(keys, k)
+	}
+
+	if !f.DisableSorting {
+		sort.Strings(keys)
+	}
+	if entry.Buffer != nil {
+		b = entry.Buffer
+	} else {
+		b = &bytes.Buffer{}
+	}
+
+	prefixFieldClashes(entry.Data)
+
+	f.Do(func() { f.init(entry) })
+
+	isColored := (f.ForceColors || f.isTerminal) && !f.DisableColors
+
+	timestampFormat := f.TimestampFormat
+	if timestampFormat == "" {
+		timestampFormat = defaultTimestampFormat
+	}
+	if isColored {
+		f.printColored(b, entry, keys, timestampFormat)
+	} else {
+		if !f.DisableTimestamp {
+			f.appendKeyValue(b, "time", entry.Time.Format(timestampFormat))
+		}
+		f.appendKeyValue(b, "level", entry.Level.String())
+		if entry.Message != "" {
+			f.appendKeyValue(b, "msg", entry.Message)
+		}
+		for _, key := range keys {
+			f.appendKeyValue(b, key, entry.Data[key])
+		}
+	}
+
+	b.WriteByte('\n')
+	return b.Bytes(), nil
+}
+
+func (f *TextFormatter) printColored(b *bytes.Buffer, entry *Entry, keys []string, timestampFormat string) {
+	var levelColor int
+	switch entry.Level {
+	case DebugLevel:
+		levelColor = gray
+	case WarnLevel:
+		levelColor = yellow
+	case ErrorLevel, FatalLevel, PanicLevel:
+		levelColor = red
+	default:
+		levelColor = blue
+	}
+
+	levelText := strings.ToUpper(entry.Level.String())[0:4]
+
+	if f.DisableTimestamp {
+		fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m %-44s ", levelColor, levelText, entry.Message)
+	} else if !f.FullTimestamp {
+		fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%04d] %-44s ", levelColor, levelText, int(entry.Time.Sub(baseTimestamp)/time.Second), entry.Message)
+	} else {
+		fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%s] %-44s ", levelColor, levelText, entry.Time.Format(timestampFormat), entry.Message)
+	}
+	for _, k := range keys {
+		v := entry.Data[k]
+		fmt.Fprintf(b, " \x1b[%dm%s\x1b[0m=", levelColor, k)
+		f.appendValue(b, v)
+	}
+}
+
+func (f *TextFormatter) needsQuoting(text string) bool {
+	if f.QuoteEmptyFields && len(text) == 0 {
+		return true
+	}
+	for _, ch := range text {
+		if !((ch >= 'a' && ch <= 'z') ||
+			(ch >= 'A' && ch <= 'Z') ||
+			(ch >= '0' && ch <= '9') ||
+			ch == '-' || ch == '.' || ch == '_' || ch == '/' || ch == '@' || ch == '^' || ch == '+') {
+			return true
+		}
+	}
+	return false
+}
+
+func (f *TextFormatter) appendKeyValue(b *bytes.Buffer, key string, value interface{}) {
+	if b.Len() > 0 {
+		b.WriteByte(' ')
+	}
+	b.WriteString(key)
+	b.WriteByte('=')
+	f.appendValue(b, value)
+}
+
+func (f *TextFormatter) appendValue(b *bytes.Buffer, value interface{}) {
+	stringVal, ok := value.(string)
+	if !ok {
+		stringVal = fmt.Sprint(value)
+	}
+
+	if !f.needsQuoting(stringVal) {
+		b.WriteString(stringVal)
+	} else {
+		b.WriteString(fmt.Sprintf("%q", stringVal))
+	}
+}

vendor/github.com/sirupsen/logrus/writer.go

@@ -0,0 +1,62 @@
+package logrus
+
+import (
+	"bufio"
+	"io"
+	"runtime"
+)
+
+func (logger *Logger) Writer() *io.PipeWriter {
+	return logger.WriterLevel(InfoLevel)
+}
+
+func (logger *Logger) WriterLevel(level Level) *io.PipeWriter {
+	return NewEntry(logger).WriterLevel(level)
+}
+
+func (entry *Entry) Writer() *io.PipeWriter {
+	return entry.WriterLevel(InfoLevel)
+}
+
+func (entry *Entry) WriterLevel(level Level) *io.PipeWriter {
+	reader, writer := io.Pipe()
+
+	var printFunc func(args ...interface{})
+
+	switch level {
+	case DebugLevel:
+		printFunc = entry.Debug
+	case InfoLevel:
+		printFunc = entry.Info
+	case WarnLevel:
+		printFunc = entry.Warn
+	case ErrorLevel:
+		printFunc = entry.Error
+	case FatalLevel:
+		printFunc = entry.Fatal
+	case PanicLevel:
+		printFunc = entry.Panic
+	default:
+		printFunc = entry.Print
+	}
+
+	go entry.writerScanner(reader, printFunc)
+	runtime.SetFinalizer(writer, writerFinalizer)
+
+	return writer
+}
+
+func (entry *Entry) writerScanner(reader *io.PipeReader, printFunc func(args ...interface{})) {
+	scanner := bufio.NewScanner(reader)
+	for scanner.Scan() {
+		printFunc(scanner.Text())
+	}
+	if err := scanner.Err(); err != nil {
+		entry.Errorf("Error while reading from Writer: %s", err)
+	}
+	reader.Close()
+}
+
+func writerFinalizer(writer *io.PipeWriter) {
+	writer.Close()
+}