Instrumenting applicatoin with logrus.

Author: Otávio Fernandes

cmd/vault-handler/download.go

@@ -5,6 +5,7 @@ import (
 
 	vaulthandler "github.com/otaviof/vault-handler/pkg/vault-handler"
 	"github.com/spf13/cobra"
+	"github.com/spf13/viper"
 )
 
 var downloadCmd = &cobra.Command{
@@ -19,10 +20,12 @@ func runDownloadCmd(cmd *cobra.Command, args []string) {
 	var manifest *vaulthandler.Manifest
 	var err error
 
+	log.Printf("runDownloadCmd")
+
 	handler := bootstrap()
 
 	for _, manifestFile := range args {
-		log.Printf("Handling manifest file: '%s'", manifestFile)
+		log.Printf("[Download] Handling manifest file: '%s'", manifestFile)
 
 		if manifest, err = vaulthandler.NewManifest(manifestFile); err != nil {
 			log.Fatalf("[ERROR] On parsing manifest: '%s'", err)
@@ -40,4 +43,8 @@ func init() {
 	flags.String("output-dir", ".", "Output directory.")
 
 	rootCmd.AddCommand(downloadCmd)
+
+	if err := viper.BindPFlags(flags); err != nil {
+		panic(err)
+	}
 }

cmd/vault-handler/vault_handler.go

@@ -1,10 +1,11 @@
 package main
 
 import (
-	"log"
+	"os"
 	"strings"
 
 	vaulthandler "github.com/otaviof/vault-handler/pkg/vault-handler"
+	log "github.com/sirupsen/logrus"
 	"github.com/spf13/cobra"
 	"github.com/spf13/viper"
 )
@@ -31,9 +32,15 @@ func configFromEnv() *vaulthandler.Config {
 
 // bootstrap creates connection with vault, by instantiating Handler.
 func bootstrap() *vaulthandler.Handler {
+	var level log.Level
 	var handler *vaulthandler.Handler
 	var err error
 
+	if level, err = log.ParseLevel(viper.GetString("log-level")); err != nil {
+		log.Fatalf("[ERROR] On parsing log-level: '%s'", err)
+	}
+	log.SetLevel(level)
+
 	config := configFromEnv()
 	if err = config.Validate(); err != nil {
 		log.Fatalf("[ERROR] On validating parameters: '%s'", err)
@@ -54,6 +61,8 @@ func bootstrap() *vaulthandler.Handler {
 func init() {
 	var err error
 
+	log.SetOutput(os.Stdout)
+
 	flags := rootCmd.PersistentFlags()
 
 	// setting up rules for environment variables
@@ -67,6 +76,7 @@ func init() {
 	flags.String("vault-role-id", "", "Vault AppRole role-id")
 	flags.String("vault-secret-id", "", "Vault AppRole secret-id")
 	flags.Bool("dry-run", false, "dry-run mode")
+	flags.String("log-level", "debug", "dry-run mode")
 
 	if err = viper.BindPFlags(flags); err != nil {
 		log.Fatal(err)

pkg/vault-handler/file.go

@@ -6,12 +6,14 @@ import (
 	"fmt"
 	"io"
 	"io/ioutil"
-	"log"
 	"path"
+
+	log "github.com/sirupsen/logrus"
 )
 
 // File definition on how to write a secret to file-system.
 type File struct {
+	logger     *log.Entry  // logger
 	group      string      // name of the group
 	properties *SecretData // using SecretData as file properties
 	payload    []byte      // data payload
@@ -22,23 +24,21 @@ func (f *File) Zip() error {
 	var buffer bytes.Buffer
 	var err error
 
-	originalPayloadLen := len(f.payload)
+	f.logger.WithField("bytes", len(f.payload)).Info("Zipping file payload")
 	gz := gzip.NewWriter(&buffer)
 
 	if _, err = gz.Write(f.payload); err != nil {
 		return err
 	}
 	if err = gz.Flush(); err != nil {
 		return err
-
 	}
 	if err = gz.Close(); err != nil {
 		return err
 	}
-
-	log.Printf("[File] Zipping payload, before and after: '%d'/'%d' bytes ",
-		originalPayloadLen, len(f.payload))
 	f.payload = buffer.Bytes()
+	f.logger.WithField("bytes", len(f.payload)).Info("Zipped file payload")
+
 	return nil
 }
 
@@ -48,7 +48,8 @@ func (f *File) Unzip() error {
 	var bufferOut bytes.Buffer
 	var err error
 
-	originalPayloadLen := len(f.payload)
+	f.logger.WithField("bytes", len(f.payload)).Info("Unzipping file payload")
+
 	bufferIn := bytes.NewBuffer(f.payload)
 	if reader, err = gzip.NewReader(bufferIn); err != nil {
 		return err
@@ -57,9 +58,9 @@ func (f *File) Unzip() error {
 		return err
 	}
 
-	log.Printf("[File] Unzipping payload, before and after: '%d'/'%d' bytes ",
-		originalPayloadLen, len(f.payload))
 	f.payload = bufferOut.Bytes()
+	f.logger.WithField("bytes", len(f.payload)).Info("Unzipped file payload")
+
 	return nil
 }
 
@@ -74,14 +75,16 @@ func (f *File) Read(baseDir string) error {
 	if f.payload, err = ioutil.ReadFile(fullPath); err != nil {
 		return err
 	}
-	log.Printf("[File] Reading '%d' bytes from '%s'", len(f.payload), fullPath)
+	f.logger.WithFields(log.Fields{"path": fullPath, "bytes": len(f.payload)}).
+		Info("Reading file content")
 
 	return nil
 }
 
 // Write contents to file-system.
 func (f *File) Write(baseDir string) error {
-	log.Printf("[File] Writting '%d' bytes on '%s'", len(f.payload), f.fileName())
+	f.logger.WithFields(log.Fields{"name": f.fileName(), "bytes": len(f.payload)}).
+		Info("Reading file content")
 	return ioutil.WriteFile(f.FilePath(baseDir), f.payload, 0600)
 }
 
@@ -107,5 +110,14 @@ func (f *File) Payload() []byte {
 
 // NewFile instance.
 func NewFile(group string, properties *SecretData, payload []byte) *File {
-	return &File{group: group, properties: properties, payload: payload}
+	return &File{
+		logger: log.WithFields(log.Fields{
+			"type":      "File",
+			"name":      properties.Name,
+			"extension": properties.Extension,
+		}),
+		group:      group,
+		properties: properties,
+		payload:    payload,
+	}
 }

pkg/vault-handler/handler.go

@@ -1,14 +1,16 @@
 package vaulthandler
 
 import (
-	"log"
 	"path"
+
+	log "github.com/sirupsen/logrus"
 )
 
 // Handler application primary runtime object.
 type Handler struct {
-	config *Config // configuration instance
-	vault  *Vault  // vault api instance
+	logger *log.Entry // logger
+	config *Config    // configuration instance
+	vault  *Vault     // vault api instance
 }
 
 // Authenticate against vault either via token directly or via AppRole, must be invoked before other
@@ -17,10 +19,10 @@ func (h *Handler) Authenticate() error {
 	var err error
 
 	if h.config.VaultToken != "" {
-		log.Printf("[Handler] Using token based authentication against Vault.")
+		h.logger.Info("Using token based authentication")
 		h.vault.TokenAuth(h.config.VaultToken)
 	} else {
-		log.Printf("[Handler] Using AppRole based authentication against Vault.")
+		h.logger.Info("Using AppRole based authentication")
 		if err = h.vault.AppRoleAuth(h.config.VaultRoleID, h.config.VaultSecretID); err != nil {
 			return err
 		}
@@ -34,23 +36,23 @@ func (h *Handler) Download(manifest *Manifest) error {
 	var err error
 
 	for group, secrets := range manifest.Secrets {
-		log.Printf("[Handler/Download] Handling secrets for '%s' group...", group)
-		log.Printf("[Handler/Download] [%s] Vault path '%s'", group, secrets.Path)
+		logger := h.logger.WithFields(log.Fields{"group": group, "vaultPath": secrets.Path})
+		logger.Info("Handling secrets")
 
 		for _, data := range secrets.Data {
+			var vaultPath = h.composeVaultPath(secrets, data)
 			var payload []byte
 
-			log.Printf("[Handler/Download] [%s] Reading data from Vault '%s.%s' (unzip: %v)",
-				group, data.Name, data.Extension, data.Unzip)
-
-			vaultPath := h.composeVaultPath(secrets, data)
-			log.Printf("[Handler/Download] [%s] '%s' path in Vault: '%s'",
-				data.Name, group, vaultPath)
+			logger.WithFields(log.Fields{
+				"name":      data.Name,
+				"extension": data.Extension,
+				"unzip":     data.Unzip,
+				"vaultPath": vaultPath,
+			}).Info("Reading data from Vault")
 
 			if payload, err = h.vault.Read(vaultPath, data.Name); err != nil {
 				return err
 			}
-
 			file := NewFile(group, &data, payload)
 
 			if data.Unzip {
@@ -72,29 +74,40 @@ func (h *Handler) Download(manifest *Manifest) error {
 func (h *Handler) Upload(manifest *Manifest) error {
 	var err error
 
-	log.Printf("[Handler/Upload] Input directory: '%s'", h.config.InputDir)
-
+	h.logger.Info("Uploading secrets...")
 	for group, secrets := range manifest.Secrets {
-		log.Printf("[Handler/Upload] Handling secrets for '%s' group...", group)
-		log.Printf("[Handler/Upload] [%s] Vault path '%s'", group, secrets.Path)
+		logger := h.logger.WithFields(log.Fields{
+			"action":    "upload",
+			"inputDir":  h.config.InputDir,
+			"group":     group,
+			"vaultPath": secrets.Path,
+		})
+		logger.Info("Handling secrets for group")
 
 		for _, data := range secrets.Data {
+			logger = logger.WithFields(log.Fields{
+				"name":      data.Name,
+				"extension": data.Extension,
+				"unzip":     data.Unzip,
+			})
+			logger.Info("Handling file")
+
 			file := NewFile(group, &data, []byte{})
 
 			if err = file.Read(h.config.InputDir); err != nil {
-				log.Printf("[Handler/Upload] error on reading file: '%s'", err)
+				logger.Error("error on reading file", err)
 				return err
 			}
 
 			if data.Unzip {
 				if err = file.Zip(); err != nil {
-					log.Printf("[Handler/Upload] error on zipping file payload: '%s'", err)
+					logger.Error("error on zipping payload", err)
 					return err
 				}
 			}
 
 			if err = h.dispense(file, h.composeVaultPath(secrets, data)); err != nil {
-				log.Printf("[Handler/Upload] Error on writting data to Vault: '%s'", err)
+				logger.Error("error on writting data to vault", err)
 				return err
 			}
 		}
@@ -146,7 +159,11 @@ func (h *Handler) composeVaultPath(secrets Secrets, data SecretData) string {
 func NewHandler(config *Config) (*Handler, error) {
 	var err error
 
-	handler := &Handler{config: config}
+	handler := &Handler{
+		config: config,
+		logger: log.WithFields(log.Fields{"type": "Handler"}),
+	}
+
 	if handler.vault, err = NewVault(config.VaultAddr); err != nil {
 		return nil, err
 	}

pkg/vault-handler/utils.go

@@ -2,8 +2,9 @@ package vaulthandler
 
 import (
 	"io/ioutil"
-	"log"
 	"os"
+
+	log "github.com/sirupsen/logrus"
 )
 
 // fileExists Check if path exists, boolean return.
@@ -16,15 +17,17 @@ func fileExists(path string) bool {
 
 // readFile Wrap up a ioutil call, using fatal log in case of error.
 func readFile(path string) []byte {
-	log.Printf("[Utils] Reading file: '%s'", path)
+	var fileBytes []byte
+	var err error
+
+	logger := log.WithField("path", path)
+	logger.Infof("Reading file bytes")
 
 	if !fileExists(path) {
-		log.Fatalf("Can't find file: '%s'", path)
+		logger.Fatal("Can't find file")
 	}
-
-	fileBytes, err := ioutil.ReadFile(path)
-	if err != nil {
-		log.Fatal(err)
+	if fileBytes, err = ioutil.ReadFile(path); err != nil {
+		logger.Fatalf("Error on read file: '%s'", err)
 	}
 	return fileBytes
 }