refactor(server): Use logrus convenience functions for logs

Makes use of the `.WithError` and `.WithField` convenience functions
in logrus to simplify log statement construction.

This has the added benefit of making it easier to correctly log
errors.

5 files changed, 59 insertions, 128 deletions

diff --git a/tools/nixery/server/builder/builder.go b/tools/nixery/server/builder/builder.go
index 14696f58a8..78d09b55b1 100644
--- a/tools/nixery/server/builder/builder.go
+++ b/tools/nixery/server/builder/builder.go
@@ -168,11 +168,10 @@ func callNix(program, image string, args []string) ([]byte, error) {
 	go logNix(program, image, errpipe)
 
 	if err = cmd.Start(); err != nil {
-		log.WithFields(log.Fields{
+		log.WithError(err).WithFields(log.Fields{
 			"image": image,
 			"cmd":   program,
-			"error": err,
-		}).Error("error starting command")
+		}).Error("error invoking Nix")
 
 		return nil, err
 	}
@@ -185,12 +184,11 @@ func callNix(program, image string, args []string) ([]byte, error) {
 	stdout, _ := ioutil.ReadAll(outpipe)
 
 	if err = cmd.Wait(); err != nil {
-		log.WithFields(log.Fields{
+		log.WithError(err).WithFields(log.Fields{
 			"image":  image,
 			"cmd":    program,
-			"error":  err,
 			"stdout": stdout,
-		}).Info("Nix execution failed")
+		}).Info("failed to invoke Nix")
 
 		return nil, err
 	}
@@ -198,10 +196,9 @@ func callNix(program, image string, args []string) ([]byte, error) {
 	resultFile := strings.TrimSpace(string(stdout))
 	buildOutput, err := ioutil.ReadFile(resultFile)
 	if err != nil {
-		log.WithFields(log.Fields{
+		log.WithError(err).WithFields(log.Fields{
 			"image": image,
 			"file":  resultFile,
-			"error": err,
 		}).Info("failed to read Nix result file")
 
 		return nil, err
@@ -303,10 +300,9 @@ func prepareLayers(ctx context.Context, s *State, image *Image, result *ImageRes
 	entry, err := uploadHashLayer(ctx, s, slkey, func(w io.Writer) error {
 		f, err := os.Open(result.SymlinkLayer.Path)
 		if err != nil {
-			log.WithFields(log.Fields{
+			log.WithError(err).WithFields(log.Fields{
 				"image": image.Name,
 				"tag":   image.Tag,
-				"error": err,
 				"layer": slkey,
 			}).Error("failed to upload symlink layer")
 
@@ -364,10 +360,9 @@ func renameObject(ctx context.Context, s *State, old, new string) error {
 	// renaming/moving them, hence a deletion call afterwards is
 	// required.
 	if err = s.Bucket.Object(old).Delete(ctx); err != nil {
-		log.WithFields(log.Fields{
-			"new":   new,
-			"old":   old,
-			"error": err,
+		log.WithError(err).WithFields(log.Fields{
+			"new": new,
+			"old": old,
 		}).Warn("failed to delete renamed object")
 
 		// this error should not break renaming and is not returned
@@ -421,19 +416,15 @@ func uploadHashLayer(ctx context.Context, s *State, key string, lw layerWriter)
 
 	err := lw(multi)
 	if err != nil {
-		log.WithFields(log.Fields{
-			"layer": key,
-			"error": err,
-		}).Error("failed to create and upload layer")
+		log.WithError(err).WithField("layer", key).
+			Error("failed to create and upload layer")
 
 		return nil, err
 	}
 
 	if err = sw.Close(); err != nil {
-		log.WithFields(log.Fields{
-			"layer": key,
-			"error": err,
-		}).Error("failed to upload layer to staging")
+		log.WithError(err).WithField("layer", key).
+			Error("failed to upload layer to staging")
 	}
 
 	sha256sum := fmt.Sprintf("%x", shasum.Sum([]byte{}))
@@ -442,10 +433,8 @@ func uploadHashLayer(ctx context.Context, s *State, key string, lw layerWriter)
 	// remains is to move it to the correct location and cache it.
 	err = renameObject(ctx, s, "staging/"+key, "layers/"+sha256sum)
 	if err != nil {
-		log.WithFields(log.Fields{
-			"layer": key,
-			"error": err,
-		}).Error("failed to move layer from staging")
+		log.WithError(err).WithField("layer", key).
+			Error("failed to move layer from staging")
 
 		return nil, err
 	}
@@ -478,7 +467,7 @@ func BuildImage(ctx context.Context, s *State, image *Image) (*BuildResult, erro
 
 	imageResult, err := prepareImage(s, image)
 	if err != nil {
-		return nil, fmt.Errorf("failed to prepare image '%s': %s", image.Name, err)
+		return nil, err
 	}
 
 	if imageResult.Error != "" {
@@ -502,10 +491,9 @@ func BuildImage(ctx context.Context, s *State, image *Image) (*BuildResult, erro
 	}
 
 	if _, err = uploadHashLayer(ctx, s, c.SHA256, lw); err != nil {
-		log.WithFields(log.Fields{
+		log.WithError(err).WithFields(log.Fields{
 			"image": image.Name,
 			"tag":   image.Tag,
-			"error": err,
 		}).Error("failed to upload config")
 
 		return nil, err
diff --git a/tools/nixery/server/builder/cache.go b/tools/nixery/server/builder/cache.go
index 916de3af16..88bf30de48 100644
--- a/tools/nixery/server/builder/cache.go
+++ b/tools/nixery/server/builder/cache.go
@@ -63,10 +63,8 @@ func (c *LocalCache) manifestFromLocalCache(key string) (json.RawMessage, bool)
 		// This is a debug log statement because failure to
 		// read the manifest key is currently expected if it
 		// is not cached.
-		log.WithFields(log.Fields{
-			"manifest": key,
-			"error":    err,
-		}).Debug("failed to read manifest from local cache")
+		log.WithError(err).WithField("manifest", key).
+			Debug("failed to read manifest from local cache")
 
 		return nil, false
 	}
@@ -74,10 +72,8 @@ func (c *LocalCache) manifestFromLocalCache(key string) (json.RawMessage, bool)
 
 	m, err := ioutil.ReadAll(f)
 	if err != nil {
-		log.WithFields(log.Fields{
-			"manifest": key,
-			"error":    err,
-		}).Error("failed to read manifest from local cache")
+		log.WithError(err).WithField("manifest", key).
+			Error("failed to read manifest from local cache")
 
 		return nil, false
 	}
@@ -96,10 +92,8 @@ func (c *LocalCache) localCacheManifest(key string, m json.RawMessage) {
 
 	err := ioutil.WriteFile(c.mdir+key, []byte(m), 0644)
 	if err != nil {
-		log.WithFields(log.Fields{
-			"manifest": key,
-			"error":    err,
-		}).Error("failed to locally cache manifest")
+		log.WithError(err).WithField("manifest", key).
+			Error("failed to locally cache manifest")
 	}
 }
 
@@ -136,10 +130,8 @@ func manifestFromCache(ctx context.Context, s *State, key string) (json.RawMessa
 
 	r, err := obj.NewReader(ctx)
 	if err != nil {
-		log.WithFields(log.Fields{
-			"manifest": key,
-			"error":    err,
-		}).Error("failed to retrieve manifest from bucket cache")
+		log.WithError(err).WithField("manifest", key).
+			Error("failed to retrieve manifest from bucket cache")
 
 		return nil, false
 	}
@@ -147,18 +139,14 @@ func manifestFromCache(ctx context.Context, s *State, key string) (json.RawMessa
 
 	m, err := ioutil.ReadAll(r)
 	if err != nil {
-		log.WithFields(log.Fields{
-			"manifest": key,
-			"error":    err,
-		}).Error("failed to read cached manifest from bucket")
+		log.WithError(err).WithField("manifest", key).
+			Error("failed to read cached manifest from bucket")
 
 		return nil, false
 	}
 
 	go s.Cache.localCacheManifest(key, m)
-	log.WithFields(log.Fields{
-		"manifest": key,
-	}).Info("retrieved manifest from GCS")
+	log.WithField("manifest", key).Info("retrieved manifest from GCS")
 
 	return json.RawMessage(m), true
 }
@@ -173,19 +161,15 @@ func cacheManifest(ctx context.Context, s *State, key string, m json.RawMessage)
 
 	size, err := io.Copy(w, r)
 	if err != nil {
-		log.WithFields(log.Fields{
-			"manifest": key,
-			"error":    err,
-		}).Error("failed to cache manifest to GCS")
+		log.WithError(err).WithField("manifest", key).
+			Error("failed to cache manifest to GCS")
 
 		return
 	}
 
 	if err = w.Close(); err != nil {
-		log.WithFields(log.Fields{
-			"manifest": key,
-			"error":    err,
-		}).Error("failed to cache manifest to GCS")
+		log.WithError(err).WithField("manifest", key).
+			Error("failed to cache manifest to GCS")
 
 		return
 	}
@@ -211,10 +195,8 @@ func layerFromCache(ctx context.Context, s *State, key string) (*manifest.Entry,
 
 	r, err := obj.NewReader(ctx)
 	if err != nil {
-		log.WithFields(log.Fields{
-			"layer": key,
-			"error": err,
-		}).Error("failed to retrieve cached layer from GCS")
+		log.WithError(err).WithField("layer", key).
+			Error("failed to retrieve cached layer from GCS")
 
 		return nil, false
 	}
@@ -223,10 +205,8 @@ func layerFromCache(ctx context.Context, s *State, key string) (*manifest.Entry,
 	jb := bytes.NewBuffer([]byte{})
 	_, err = io.Copy(jb, r)
 	if err != nil {
-		log.WithFields(log.Fields{
-			"layer": key,
-			"error": err,
-		}).Error("failed to read cached layer from GCS")
+		log.WithError(err).WithField("layer", key).
+			Error("failed to read cached layer from GCS")
 
 		return nil, false
 	}
@@ -234,10 +214,8 @@ func layerFromCache(ctx context.Context, s *State, key string) (*manifest.Entry,
 	var entry manifest.Entry
 	err = json.Unmarshal(jb.Bytes(), &entry)
 	if err != nil {
-		log.WithFields(log.Fields{
-			"layer": key,
-			"error": err,
-		}).Error("failed to unmarshal cached layer")
+		log.WithError(err).WithField("layer", key).
+			Error("failed to unmarshal cached layer")
 
 		return nil, false
 	}
@@ -257,19 +235,15 @@ func cacheLayer(ctx context.Context, s *State, key string, entry manifest.Entry)
 
 	_, err := io.Copy(w, bytes.NewReader(j))
 	if err != nil {
-		log.WithFields(log.Fields{
-			"layer": key,
-			"error": err,
-		}).Error("failed to cache layer")
+		log.WithError(err).WithField("layer", key).
+			Error("failed to cache layer")
 
 		return
 	}
 
 	if err = w.Close(); err != nil {
-		log.WithFields(log.Fields{
-			"layer": key,
-			"error": err,
-		}).Error("failed to cache layer")
+		log.WithError(err).WithField("layer", key).
+			Error("failed to cache layer")
 
 		return
 	}
diff --git a/tools/nixery/server/config/config.go b/tools/nixery/server/config/config.go
index 9447975aa9..fe05734ee6 100644
--- a/tools/nixery/server/config/config.go
+++ b/tools/nixery/server/config/config.go
@@ -36,16 +36,11 @@ func signingOptsFromEnv() *storage.SignedURLOptions {
 		return nil
 	}
 
-	log.WithFields(log.Fields{
-		"account": id,
-	}).Info("GCS URL signing enabled")
+	log.WithField("account", id).Info("GCS URL signing enabled")
 
 	k, err := ioutil.ReadFile(path)
 	if err != nil {
-		log.WithFields(log.Fields{
-			"file":  path,
-			"error": err,
-		}).Fatal("failed to read GCS signing key")
+		log.WithError(err).WithField("file", path).Fatal("failed to read GCS signing key")
 	}
 
 	return &storage.SignedURLOptions{
diff --git a/tools/nixery/server/config/pkgsource.go b/tools/nixery/server/config/pkgsource.go
index 3a817f3d76..95236c4b0d 100644
--- a/tools/nixery/server/config/pkgsource.go
+++ b/tools/nixery/server/config/pkgsource.go
@@ -132,9 +132,7 @@ func (p *PkgsPath) CacheKey(pkgs []string, tag string) string {
 // specified, the Nix code will default to a recent NixOS channel.
 func pkgSourceFromEnv() (PkgSource, error) {
 	if channel := os.Getenv("NIXERY_CHANNEL"); channel != "" {
-		log.WithFields(log.Fields{
-			"channel": channel,
-		}).Info("using Nix package set from Nix channel or commit")
+		log.WithField("channel", channel).Info("using Nix package set from Nix channel or commit")
 
 		return &NixChannel{
 			channel: channel,
@@ -142,9 +140,7 @@ func pkgSourceFromEnv() (PkgSource, error) {
 	}
 
 	if git := os.Getenv("NIXERY_PKGS_REPO"); git != "" {
-		log.WithFields(log.Fields{
-			"repo": git,
-		}).Info("using NIx package set from git repository")
+		log.WithField("repo", git).Info("using NIx package set from git repository")
 
 		return &GitSource{
 			repository: git,
@@ -152,9 +148,7 @@ func pkgSourceFromEnv() (PkgSource, error) {
 	}
 
 	if path := os.Getenv("NIXERY_PKGS_PATH"); path != "" {
-		log.WithFields(log.Fields{
-			"path": path,
-		}).Info("using Nix package set at local path")
+		log.WithField("path", path).Info("using Nix package set at local path")
 
 		return &PkgsPath{
 			path: path,
diff --git a/tools/nixery/server/main.go b/tools/nixery/server/main.go
index babf50790f..f38fab2f2a 100644
--- a/tools/nixery/server/main.go
+++ b/tools/nixery/server/main.go
@@ -68,9 +68,7 @@ var (
 // The Docker client is known to follow redirects, but this might not be true
 // for all other registry clients.
 func constructLayerUrl(cfg *config.Config, digest string) (string, error) {
-	log.WithFields(log.Fields{
-		"layer": digest,
-	}).Info("redirecting layer request to bucket")
+	log.WithField("layer", digest).Info("redirecting layer request to bucket")
 	object := "layers/" + digest
 
 	if cfg.Signing != nil {
@@ -92,18 +90,13 @@ func constructLayerUrl(cfg *config.Config, digest string) (string, error) {
 func prepareBucket(ctx context.Context, cfg *config.Config) *storage.BucketHandle {
 	client, err := storage.NewClient(ctx)
 	if err != nil {
-		log.WithFields(log.Fields{
-			"error": err,
-		}).Fatal("failed to set up Cloud Storage client")
+		log.WithError(err).Fatal("failed to set up Cloud Storage client")
 	}
 
 	bkt := client.Bucket(cfg.Bucket)
 
 	if _, err := bkt.Attrs(ctx); err != nil {
-		log.WithFields(log.Fields{
-			"error":  err,
-			"bucket": cfg.Bucket,
-		}).Fatal("could not access configured bucket")
+		log.WithError(err).WithField("bucket", cfg.Bucket).Fatal("could not access configured bucket")
 	}
 
 	return bkt
@@ -188,10 +181,9 @@ func (h *registryHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 		if err != nil {
 			writeError(w, 500, "UNKNOWN", "image build failure")
 
-			log.WithFields(log.Fields{
+			log.WithError(err).WithFields(log.Fields{
 				"image": imageName,
 				"tag":   imageTag,
-				"error": err,
 			}).Error("failed to build image manifest")
 
 			return
@@ -207,7 +199,7 @@ func (h *registryHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 				"image":    imageName,
 				"tag":      imageTag,
 				"packages": buildResult.Pkgs,
-			}).Error("could not find Nix packages")
+			}).Warn("could not find Nix packages")
 
 			return
 		}
@@ -229,11 +221,7 @@ func (h *registryHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 		url, err := constructLayerUrl(&h.state.Cfg, digest)
 
 		if err != nil {
-			log.WithFields(log.Fields{
-				"layer": digest,
-				"error": err,
-			}).Error("failed to sign GCS URL")
-
+			log.WithError(err).WithField("layer", digest).Error("failed to sign GCS URL")
 			writeError(w, 500, "UNKNOWN", "could not serve layer")
 			return
 		}
@@ -243,9 +231,7 @@ func (h *registryHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	log.WithFields(log.Fields{
-		"uri": r.RequestURI,
-	}).Info("unsupported registry route")
+	log.WithField("uri", r.RequestURI).Info("unsupported registry route")
 
 	w.WriteHeader(404)
 }
@@ -253,28 +239,22 @@ func (h *registryHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 func main() {
 	cfg, err := config.FromEnv()
 	if err != nil {
-		log.WithFields(log.Fields{
-			"error": err,
-		}).Fatal("failed to load configuration")
+		log.WithError(err).Fatal("failed to load configuration")
 	}
 
 	ctx := context.Background()
 	bucket := prepareBucket(ctx, &cfg)
 	cache, err := builder.NewCache()
 	if err != nil {
-		log.WithFields(log.Fields{
-			"error": err,
-		}).Fatal("failed to instantiate build cache")
+		log.WithError(err).Fatal("failed to instantiate build cache")
 	}
 
 	var pop layers.Popularity
 	if cfg.PopUrl != "" {
 		pop, err = downloadPopularity(cfg.PopUrl)
 		if err != nil {
-			log.WithFields(log.Fields{
-				"error":  err,
-				"popURL": cfg.PopUrl,
-			}).Fatal("failed to fetch popularity information")
+			log.WithError(err).WithField("popURL", cfg.PopUrl).
+				Fatal("failed to fetch popularity information")
 		}
 	}
 
@@ -288,7 +268,7 @@ func main() {
 	log.WithFields(log.Fields{
 		"version": version,
 		"port":    cfg.Port,
-	}).Info("Starting Nixery")
+	}).Info("starting Nixery")
 
 	// All /v2/ requests belong to the registry handler.
 	http.Handle("/v2/", &registryHandler{