feat(log): add basic support for logging output

commands/commands.go

@@ -1,9 +1,69 @@
 package commands
 
-import "github.com/spf13/cobra"
+import (
+	"io"
+	"os"
+
+	"github.com/rs/zerolog"
+	"github.com/rs/zerolog/log"
+	"github.com/spf13/cobra"
+)
 
 type runEFunc func(cmd *cobra.Command, _ []string) error
 
+func WithPrettyLogging(
+	f func(cmd *cobra.Command, args []string) error,
+) func(cmd *cobra.Command, args []string) error {
+	return func(cmd *cobra.Command, args []string) error {
+		err := SetupZerolog(cmd)
+		if err != nil {
+			return err
+		}
+
+		return f(cmd, args)
+	}
+}
+
+func SetupZerolog(cmd *cobra.Command) error {
+	var levelStr string
+	if v := os.Getenv("EVM_DEBUG"); v != "" {
+		levelStr = "debug"
+	} else if v := os.Getenv("EVM_LOG_LEVEL"); v != "" {
+		levelStr = v
+	}
+
+	var out io.Writer = os.Stderr
+
+	if cmd != nil {
+		out = cmd.OutOrStderr()
+		fl := cmd.Flag("log-level")
+		if fl != nil && (fl.Changed || levelStr == "") {
+			levelStr = fl.Value.String()
+		}
+	}
+
+	if levelStr == "" {
+		levelStr = "info"
+	}
+
+	level, err := zerolog.ParseLevel(levelStr)
+	if err != nil {
+		return err
+	}
+
+	zerolog.SetGlobalLevel(level)
+	zerolog.TimeFieldFormat = ""
+
+	output := zerolog.ConsoleWriter{Out: out}
+	output.FormatTimestamp = func(i interface{}) string {
+		return ""
+	}
+
+	log.Logger = zerolog.New(output).With().Timestamp().Logger()
+
+	return nil
+}
+
 type validArgsFunc func(
 	cmd *cobra.Command,
 	args []string,

commands/config.go

@@ -11,7 +11,7 @@ func NewConfig(mgr *manager.Manager) (*cobra.Command, error) {
 		Short:     "Show evm environment/setup details",
 		Aliases:   []string{"env", "info"},
 		ValidArgs: []string{},
-		RunE:      configRunE(mgr),
+		RunE:      WithPrettyLogging(configRunE(mgr)),
 	}
 
 	cmd.Flags().StringP("format", "f", "", "output format (yaml or json)")

commands/evm.go

@@ -11,6 +11,11 @@ func NewEvm(mgr *manager.Manager) (*cobra.Command, error) {
 		Short: "A simple and opinionated Emacs Version Manager and build tool",
 	}
 
+	cmd.PersistentFlags().StringP(
+		"log-level", "l", "info",
+		"one of: trace, debug, info, warn, error, fatal, panic",
+	)
+
 	configCmd, err := NewConfig(mgr)
 	if err != nil {
 		return nil, err

commands/exec.go

@@ -22,7 +22,7 @@ func NewExec(mgr *manager.Manager) (*cobra.Command, error) {
 		DisableFlagsInUseLine: true,
 		Hidden:                true,
 		ValidArgsFunction:     execValidArgs(mgr),
-		RunE:                  execRunE(mgr),
+		RunE:                  WithPrettyLogging(execRunE(mgr)),
 	}
 
 	return cmd, nil

commands/list.go

@@ -15,7 +15,7 @@ func NewList(mgr *manager.Manager) (*cobra.Command, error) {
 		Aliases:           []string{"ls", "versions"},
 		Args:              cobra.ExactArgs(0),
 		ValidArgsFunction: noValidArgs,
-		RunE:              listRunE(mgr),
+		RunE:              WithPrettyLogging(listRunE(mgr)),
 	}
 
 	cmd.Flags().StringP("format", "f", "", "output format (yaml or json)")

commands/rehash.go

@@ -13,7 +13,7 @@ func NewRehash(mgr *manager.Manager) (*cobra.Command, error) {
 		Short:             "Update shims for all or specific versions",
 		Aliases:           []string{"reshim"},
 		ValidArgsFunction: rehashValidArgs(mgr),
-		RunE:              rehashRunE(mgr),
+		RunE:              WithPrettyLogging(rehashRunE(mgr)),
 	}
 
 	return cmd, nil

commands/use.go

@@ -14,7 +14,7 @@ func NewUse(mgr *manager.Manager) (*cobra.Command, error) {
 		Aliases:           []string{"activate", "switch"},
 		Args:              cobra.ExactArgs(1),
 		ValidArgsFunction: useValidArgs(mgr),
-		RunE:              useRunE(mgr),
+		RunE:              WithPrettyLogging(useRunE(mgr)),
 	}
 
 	return cmd, nil

go.mod

@@ -3,6 +3,7 @@ module github.com/jimeh/evm
 go 1.17
 
 require (
+	github.com/rs/zerolog v1.26.1
 	github.com/sethvargo/go-envconfig v0.5.0
 	github.com/spf13/cobra v1.3.0
 	gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b

go.sum

@@ -277,6 +277,7 @@ github.com/pascaldekloe/goe v0.1.0/go.mod h1:lzWF7FIEvWOWxwDKqyGYQf6ZUaNfKdP144T
 github.com/pelletier/go-toml v1.9.4/go.mod h1:u1nR/EPcESfeI/szUZKdtJ0xRNbUoANCkoOuaOx1Y+c=
 github.com/pkg/errors v0.8.0/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
 github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
+github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
 github.com/pkg/sftp v1.10.1/go.mod h1:lYOWFsE0bwd1+KfKJaKeuokY15vzFx25BLbzYYoAxZI=
 github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
 github.com/posener/complete v1.1.1/go.mod h1:em0nMJCgc9GFtwrmVmEMR/ZL6WyhyjMBndrE9hABlRI=
@@ -295,6 +296,9 @@ github.com/prometheus/procfs v0.0.2/go.mod h1:TjEm7ze935MbeOT/UhFTIMYKhuLP4wbCsT
 github.com/prometheus/procfs v0.0.8/go.mod h1:7Qr8sr6344vo1JqZ6HhLceV9o3AJ1Ff+GxbHq6oeK9A=
 github.com/rogpeppe/fastuuid v1.2.0/go.mod h1:jVj6XXZzXRy/MSR5jhDC/2q6DgLz+nrA6LYCDYWNEvQ=
 github.com/rogpeppe/go-internal v1.3.0/go.mod h1:M8bDsm7K2OlrFYOpmOWEs/qY81heoFRclV5y23lUDJ4=
+github.com/rs/xid v1.3.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg=
+github.com/rs/zerolog v1.26.1 h1:/ihwxqH+4z8UxyI70wM1z9yCvkWcfz/a3mj48k/Zngc=
+github.com/rs/zerolog v1.26.1/go.mod h1:/wSSJWX7lVrsOwlbyTRSOJvqRlc+WjWlfes+CiJ+tmc=
 github.com/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM=
 github.com/ryanuber/columnize v0.0.0-20160712163229-9b3edd62028f/go.mod h1:sm1tb6uqfes/u+d4ooFouqFdy9/2g9QGwK3SQygK0Ts=
 github.com/sagikazarmark/crypt v0.3.0/go.mod h1:uD/D+6UF4SrIR1uGEv7bBNkNqLGqUr43MRiaGWX1Nig=
@@ -328,6 +332,7 @@ github.com/yuin/goldmark v1.1.27/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9de
 github.com/yuin/goldmark v1.1.32/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9decYSb74=
 github.com/yuin/goldmark v1.2.1/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9decYSb74=
 github.com/yuin/goldmark v1.3.5/go.mod h1:mwnBkeHKe2W/ZEtQ+71ViKU8L12m81fl3OWwC1Zlc8k=
+github.com/yuin/goldmark v1.4.0/go.mod h1:mwnBkeHKe2W/ZEtQ+71ViKU8L12m81fl3OWwC1Zlc8k=
 go.etcd.io/etcd/api/v3 v3.5.1/go.mod h1:cbVKeC6lCfl7j/8jBhAK6aIYO9XOjdptoxU/nLQcPvs=
 go.etcd.io/etcd/client/pkg/v3 v3.5.1/go.mod h1:IJHfcCEKxYu1Os13ZdwCwIUTUVGYTSAM3YSwc9/Ac1g=
 go.etcd.io/etcd/client/v2 v2.305.1/go.mod h1:pMEacxZW7o8pg4CrFE7pquyCJJzZvkvdD2RibOCCCGs=
@@ -352,6 +357,7 @@ golang.org/x/crypto v0.0.0-20190923035154-9ee001bba392/go.mod h1:/lpIB1dKB+9EgE3
 golang.org/x/crypto v0.0.0-20191011191535-87dc89f01550/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI=
 golang.org/x/crypto v0.0.0-20200622213623-75b288015ac9/go.mod h1:LzIPMQfyMNhhGPhUkYOs5KpL4U8rLKemX1yGLhDgUto=
 golang.org/x/crypto v0.0.0-20210817164053-32db794688a5/go.mod h1:GvvjBRRGRdwPK5ydBHafDWAxML/pGHZbMvKqRZ5+Abc=
+golang.org/x/crypto v0.0.0-20211215165025-cf75a172585e/go.mod h1:P+XmwS30IXTQdn5tA2iutPOUgjI07+tq3H3K9MVA1s8=
 golang.org/x/exp v0.0.0-20190121172915-509febef88a4/go.mod h1:CJ0aWSM057203Lf6IL+f9T1iT9GByDxfZKAQTCR3kQA=
 golang.org/x/exp v0.0.0-20190306152737-a1d7652674e8/go.mod h1:CJ0aWSM057203Lf6IL+f9T1iT9GByDxfZKAQTCR3kQA=
 golang.org/x/exp v0.0.0-20190510132918-efd6b22b2522/go.mod h1:ZjyILWgesfNpC6sMxTJOJm9Kp84zZh5NQWvqDGG3Qr8=
@@ -428,6 +434,7 @@ golang.org/x/net v0.0.0-20210316092652-d523dce5a7f4/go.mod h1:RBQZq4jEuRlivfhVLd
 golang.org/x/net v0.0.0-20210405180319-a5a99cb37ef4/go.mod h1:p54w0d4576C0XHj96bSt6lcn1PtDYWL6XObtHCRCNQM=
 golang.org/x/net v0.0.0-20210410081132-afb366fc7cd1/go.mod h1:9tjilg8BloeKEkVJvy7fQ90B1CfIiPueXVOjqfkSzI8=
 golang.org/x/net v0.0.0-20210503060351-7fd8e65b6420/go.mod h1:9nx3DQGgdP8bBQD5qxJ1jj9UTztislL4KSBs9R2vV5Y=
+golang.org/x/net v0.0.0-20210805182204-aaa1db679c0d/go.mod h1:9nx3DQGgdP8bBQD5qxJ1jj9UTztislL4KSBs9R2vV5Y=
 golang.org/x/net v0.0.0-20210813160813-60bc85c4be6d/go.mod h1:9nx3DQGgdP8bBQD5qxJ1jj9UTztislL4KSBs9R2vV5Y=
 golang.org/x/oauth2 v0.0.0-20180821212333-d2e6202438be/go.mod h1:N/0e6XlmueqKjAGxoOufVs8QHGRruUQn6yWY3a++T0U=
 golang.org/x/oauth2 v0.0.0-20190226205417-e64efc72b421/go.mod h1:gOpvHmFTYa4IltrdGE7lF6nIHvwfUNPOp7c8zoXwtLw=
@@ -515,6 +522,7 @@ golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBc
 golang.org/x/sys v0.0.0-20210616094352-59db8d763f22/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210806184541-e5e7981a1069/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
+golang.org/x/sys v0.0.0-20210809222454-d867a43fc93e/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210816183151-1e6c022a8912/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210823070655-63515b42dcdf/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210908233432-aa78b53d3365/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
@@ -589,6 +597,7 @@ golang.org/x/tools v0.1.2/go.mod h1:o0xws9oXOQQZyjljx8fwUC0k7L1pTE6eaCbjGeHmOkk=
 golang.org/x/tools v0.1.3/go.mod h1:o0xws9oXOQQZyjljx8fwUC0k7L1pTE6eaCbjGeHmOkk=
 golang.org/x/tools v0.1.4/go.mod h1:o0xws9oXOQQZyjljx8fwUC0k7L1pTE6eaCbjGeHmOkk=
 golang.org/x/tools v0.1.5/go.mod h1:o0xws9oXOQQZyjljx8fwUC0k7L1pTE6eaCbjGeHmOkk=
+golang.org/x/tools v0.1.7/go.mod h1:LGqMHiF4EqQNHR1JncWGqT5BVaXmza+X+BDGol+dOxo=
 golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
 golang.org/x/xerrors v0.0.0-20191011141410-1b5146add898/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
 golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=

manager/manager.go

@@ -11,6 +11,8 @@ import (
 	"path/filepath"
 	"strings"
 	"syscall"
+
+	"github.com/rs/zerolog/log"
 )
 
 var (
@@ -54,12 +56,20 @@ func (m *Manager) Get(ctx context.Context, version string) (*Version, error) {
 }
 
 func (m *Manager) Use(ctx context.Context, version string) error {
+	log.Debug().Str("version", version).Msg("use version")
+
 	ver, err := m.Get(ctx, version)
 	if err != nil {
 		return err
 	}
 
 	currentFile := filepath.Join(m.Config.Paths.Root, currentFileName)
+
+	log.Debug().
+		Str("path", currentFile).
+		Str("content", ver.Version).
+		Msg("updating current file")
+
 	err = os.WriteFile(currentFile, []byte(ver.Version), 0o644)
 	if err != nil {
 		return err
@@ -104,6 +114,13 @@ func (m *Manager) rehashVersions(
 	tidy bool,
 	versions []*Version,
 ) error {
+	if log.Debug().Enabled() {
+		var vers []string
+		for _, v := range versions {
+			vers = append(vers, v.Version)
+		}
+		log.Debug().Strs("versions", vers).Msg("reshashing versions")
+	}
 
 	programs := map[string]bool{}
 	for _, ver := range versions {
@@ -113,6 +130,14 @@ func (m *Manager) rehashVersions(
 		}
 	}
 
+	log.Debug().
+		Str("path", m.Config.Paths.Shims).
+		Msg("ensure shims directory exists")
+	err := os.MkdirAll(m.Config.Paths.Shims, 0o755)
+	if err != nil {
+		return err
+	}
+
 	shims, err := m.ListShims(ctx)
 	if err != nil {
 		return err
@@ -129,13 +154,10 @@ func (m *Manager) rehashVersions(
 		return err
 	}
 
-	err = os.MkdirAll(m.Config.Paths.Shims, 0o755)
-	if err != nil {
-		return err
-	}
-
 	for name := range programs {
 		shimFile := filepath.Join(m.Config.Paths.Shims, name)
+
+		log.Debug().Str("path", shimFile).Msg("writing shim")
 		err = os.WriteFile(shimFile, shim, 0o755)
 		if err != nil {
 			return err
@@ -157,9 +179,11 @@ func (m *Manager) rehashVersions(
 		delete(shimMap, name)
 	}
 
-	if tidy {
+	if tidy && len(shimMap) > 0 {
+		log.Debug().Msg("tidying shims")
 		for name := range shimMap {
 			shimFile := filepath.Join(m.Config.Paths.Shims, name)
+			log.Debug().Str("path", shimFile).Msg("removing shim")
 			err := os.Remove(shimFile)
 			if err != nil {
 				return err
@@ -191,6 +215,8 @@ func (m *Manager) shim() ([]byte, error) {
 }
 
 func (m *Manager) ListShims(ctx context.Context) ([]string, error) {
+	log.Debug().Str("path", m.Config.Paths.Shims).Msg("reading shims")
+
 	entries, err := os.ReadDir(m.Config.Paths.Shims)
 	if err != nil {
 		if errors.Is(err, fs.ErrNotExist) {
@@ -263,6 +289,12 @@ func (m *Manager) ExecVersion(
 		}
 	}
 
+	log.Debug().
+		Str("bin", bin).
+		Str("extra_path", ver.BinDir).
+		Strs("args", args).
+		Msg("executing")
+
 	return syscall.Exec(bin, execArgs, execEnv)
 }