From ee4e05b411a3245fe2860c66681c6162d5a71192 Mon Sep 17 00:00:00 2001 From: Karl Fischer Date: Fri, 2 Oct 2020 19:23:08 +0200 Subject: [PATCH] Proper logging (#52) --- .gitignore | 2 + CHANGELOG.md | 5 +- Makefile | 2 + README.md | 6 +- cli/append.go | 25 ++--- cli/cat.go | 20 ++-- cli/cd.go | 17 ++- cli/command.go | 1 + cli/cp.go | 17 ++- cli/grep.go | 10 +- cli/ls.go | 17 ++- cli/mv.go | 17 ++- cli/rm.go | 18 ++-- client/client.go | 5 +- client/delete.go | 4 + client/list.go | 2 + client/read.go | 4 + client/traverse.go | 2 +- client/write.go | 4 + completer/completer.go | 4 +- log/log.go | 157 ++++++++++++++++++---------- main.go | 46 ++++---- test/run.sh | 2 +- test/suites/commands/ls.bats | 2 +- test/suites/edge-cases/logging.bats | 33 ++++++ test/suites/edge-cases/params.bats | 6 +- test/util/util.bash | 1 + 27 files changed, 267 insertions(+), 162 deletions(-) create mode 100644 test/suites/edge-cases/logging.bats diff --git a/.gitignore b/.gitignore index 264a0819..a8df35bf 100644 --- a/.gitignore +++ b/.gitignore @@ -2,3 +2,5 @@ *.swp build/ test/bin +vsh_trace.log + diff --git a/CHANGELOG.md b/CHANGELOG.md index c4a9bca1..872357c7 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,8 +1,9 @@ -## v0.7.1 (TBD) +## v0.7.1 (October 2, 2020) BUG FIXES: -* Proper return codes [#51](https://github.com/fishi0x01/vsh/pull/51) +* Proper return codes ([#51](https://github.com/fishi0x01/vsh/pull/51)) +* Proper logging ([#52](https://github.com/fishi0x01/vsh/pull/52)) ## v0.7.0 (September 26, 2020) diff --git a/Makefile b/Makefile index 2489ff4a..314aa31c 100644 --- a/Makefile +++ b/Makefile @@ -21,9 +21,11 @@ get-bats: mkdir -p test/bin/core mkdir -p test/bin/plugins/bats-assert mkdir -p test/bin/plugins/bats-support + mkdir -p test/bin/plugins/bats-file curl -sL https://github.com/bats-core/bats-core/archive/v1.2.0.tar.gz | tar xvz --strip 1 -C test/bin/core curl -sL https://github.com/bats-core/bats-assert/archive/v2.0.0.tar.gz | tar xvz --strip 1 -C test/bin/plugins/bats-assert curl -sL https://github.com/bats-core/bats-support/archive/v0.3.0.tar.gz | tar xvz --strip 1 -C test/bin/plugins/bats-support + curl -sL https://github.com/bats-core/bats-file/archive/v0.2.0.tar.gz | tar xvz --strip 1 -C test/bin/plugins/bats-file integration-tests: test/run.sh diff --git a/README.md b/README.md index a91be66c..2de1afda 100644 --- a/README.md +++ b/README.md @@ -179,7 +179,7 @@ Working on vault secrets can be critical, making quality and correct behavior a That being said, `vsh` is still a small open source project, meaning we cannot make any guarantees. However, we put strong emphasis on [TDD](https://en.wikipedia.org/wiki/Test-driven_development). Every PR is tested with an extensive [suite](test/suites) of integration tests. -Most tests run on KV1 and KV2 and every test runs against vault `1.0.0` and `1.5.3`, i.e., versions in between should also be compatible. +Most tests run on KV1 and KV2 and every test runs against vault `1.0.0` and `1.5.4`, i.e., versions in between should also be compatible. ## Local Development @@ -193,3 +193,7 @@ make compile make get-bats make integration-tests ``` + +## Debugging + +The `-v` option enables verbose mode, which also creates a `vsh_trace.log` file to log any error object from the vault API. diff --git a/cli/append.go b/cli/append.go index 003849c4..29bff567 100644 --- a/cli/append.go +++ b/cli/append.go @@ -2,7 +2,6 @@ package cli import ( "fmt" - "io" "strconv" "strings" @@ -30,20 +29,16 @@ type AppendCommand struct { name string client *client.Client - stderr io.Writer - stdout io.Writer Source string Target string Mode AppendMode } // NewAppendCommand creates a new AppendCommand parameter container -func NewAppendCommand(c *client.Client, stdout io.Writer, stderr io.Writer) *AppendCommand { +func NewAppendCommand(c *client.Client) *AppendCommand { return &AppendCommand{ name: "append", client: c, - stdout: stdout, - stderr: stderr, Mode: ModeSkip, } } @@ -58,10 +53,6 @@ func (cmd *AppendCommand) IsSane() bool { return cmd.Source != "" && cmd.Target != "" && cmd.Mode != ModeInvalid } -func printUsage() { - fmt.Println("Usage:\nappend [-f|--force|-r|--rename|-s|--skip]") -} - func isFlag(flag string) bool { return strings.HasPrefix(flag, "-") } @@ -108,11 +99,15 @@ func (cmd *AppendCommand) tryParse(args []string) (success bool) { return false } +// PrintUsage print command usage +func (cmd *AppendCommand) PrintUsage() { + log.UserInfo("Usage:\nappend [-f|--force|-r|--rename|-s|--skip]") +} + // Parse parses the arguments and returns true on success; otherwise it prints usage and returns false func (cmd *AppendCommand) Parse(args []string) error { success := cmd.tryParse(args) if !success { - printUsage() return fmt.Errorf("cannot parse arguments") } return nil @@ -125,12 +120,12 @@ func (cmd *AppendCommand) Run() int { src := cmd.client.GetType(newSrcPwd) if src != client.LEAF { - log.NotAValidPath(newSrcPwd) + log.UserError("Not a valid path for operation: %s", newSrcPwd) return 1 } if err := cmd.mergeSecrets(newSrcPwd, newTargetPwd); err != nil { - log.Error("Append failed: " + err.Error()) + log.AppError("Append failed: " + err.Error()) return 1 } return 0 @@ -193,9 +188,9 @@ func (cmd *AppendCommand) mergeSecrets(source string, target string) error { fmt.Println(err) return err } - log.Info("Appended values from %s to %s", source, target) + log.UserDebug("Appended values from %s to %s", source, target) if len(skippedKeys) > 0 { - log.Info("Handled conflicting keys according to the '%s' strategy. Keys: %s", onConflict, strings.Join(skippedKeys, ", ")) + log.UserDebug("Handled conflicting keys according to the '%s' strategy. Keys: %s", onConflict, strings.Join(skippedKeys, ", ")) } return nil } diff --git a/cli/cat.go b/cli/cat.go index 3a37e613..e9df2f07 100644 --- a/cli/cat.go +++ b/cli/cat.go @@ -2,8 +2,6 @@ package cli import ( "fmt" - "io" - "github.com/fishi0x01/vsh/client" "github.com/fishi0x01/vsh/log" ) @@ -13,18 +11,14 @@ type CatCommand struct { name string client *client.Client - stderr io.Writer - stdout io.Writer Path string } // NewCatCommand creates a new CatCommand parameter container -func NewCatCommand(c *client.Client, stdout io.Writer, stderr io.Writer) *CatCommand { +func NewCatCommand(c *client.Client) *CatCommand { return &CatCommand{ name: "cat", client: c, - stderr: stderr, - stdout: stdout, } } @@ -38,10 +32,14 @@ func (cmd *CatCommand) IsSane() bool { return cmd.Path != "" } +// PrintUsage print command usage +func (cmd *CatCommand) PrintUsage() { + log.UserInfo("Usage:\ncat ") +} + // Parse given arguments and return status func (cmd *CatCommand) Parse(args []string) error { if len(args) != 2 { - fmt.Println("Usage:\ncat ") return fmt.Errorf("cannot parse arguments") } cmd.Path = args[1] @@ -63,15 +61,15 @@ func (cmd *CatCommand) Run() int { if rec, ok := v.(map[string]interface{}); ok { // KV 2 for kk, vv := range rec { - fmt.Fprintln(cmd.stdout, kk, "=", vv) + log.UserInfo("%s = %s", kk, vv) } } else { // KV 1 - fmt.Fprintln(cmd.stdout, k, "=", v) + log.UserInfo("%s = %s", k, v) } } } else { - log.NotAValidPath(absPath) + log.UserError("Not a valid path for operation: %s", absPath) return 1 } return 0 diff --git a/cli/cd.go b/cli/cd.go index c3141c17..c4551914 100644 --- a/cli/cd.go +++ b/cli/cd.go @@ -2,7 +2,6 @@ package cli import ( "fmt" - "io" "strings" "github.com/fishi0x01/vsh/client" @@ -14,18 +13,14 @@ type CdCommand struct { name string client *client.Client - stderr io.Writer - stdout io.Writer Path string } // NewCdCommand creates a new CdCommand parameter container -func NewCdCommand(c *client.Client, stdout io.Writer, stderr io.Writer) *CdCommand { +func NewCdCommand(c *client.Client) *CdCommand { return &CdCommand{ name: "cd", client: c, - stdout: stdout, - stderr: stderr, } } @@ -39,10 +34,14 @@ func (cmd *CdCommand) IsSane() bool { return cmd.Path != "" } +// PrintUsage print command usage +func (cmd *CdCommand) PrintUsage() { + log.UserInfo("Usage:\ncd ") +} + // Parse given arguments and return status func (cmd *CdCommand) Parse(args []string) error { if len(args) != 2 { - fmt.Println("Usage:\ncd ") return fmt.Errorf("cannot parse arguments") } cmd.Path = args[1] @@ -56,12 +55,12 @@ func (cmd *CdCommand) Run() int { t := cmd.client.GetType(newPwd) if t == client.NONE { - log.NotAValidPath(newPwd) + log.UserError("Not a valid path for operation: %s", newPwd) return 1 } if t == client.LEAF { - log.NotAValidPath(newPwd) + log.UserError("Not a valid path for operation: %s", newPwd) return 1 } diff --git a/cli/command.go b/cli/command.go index da7a9f34..0ed41560 100644 --- a/cli/command.go +++ b/cli/command.go @@ -12,6 +12,7 @@ type Command interface { Run() int GetName() string IsSane() bool + PrintUsage() Parse(args []string) error } diff --git a/cli/cp.go b/cli/cp.go index 81d9bc7c..399b2df2 100644 --- a/cli/cp.go +++ b/cli/cp.go @@ -2,7 +2,6 @@ package cli import ( "fmt" - "io" "path/filepath" "github.com/fishi0x01/vsh/client" @@ -14,19 +13,15 @@ type CopyCommand struct { name string client *client.Client - stderr io.Writer - stdout io.Writer Source string Target string } // NewCopyCommand creates a new CopyCommand parameter container -func NewCopyCommand(c *client.Client, stdout io.Writer, stderr io.Writer) *CopyCommand { +func NewCopyCommand(c *client.Client) *CopyCommand { return &CopyCommand{ name: "cp", client: c, - stdout: stdout, - stderr: stderr, } } @@ -40,10 +35,14 @@ func (cmd *CopyCommand) IsSane() bool { return cmd.Source != "" && cmd.Target != "" } +// PrintUsage print command usage +func (cmd *CopyCommand) PrintUsage() { + log.UserInfo("Usage:\ncp ") +} + // Parse given arguments and return status func (cmd *CopyCommand) Parse(args []string) error { if len(args) != 3 { - fmt.Println("Usage:\ncp ") return fmt.Errorf("cannot parse arguments") } cmd.Source = args[1] @@ -62,7 +61,7 @@ func (cmd *CopyCommand) Run() int { case client.NODE: runCommandWithTraverseTwoPaths(cmd.client, newSrcPwd, newTargetPwd, cmd.copySecret) default: - log.NotAValidPath(newSrcPwd) + log.UserError("Not a valid path for operation: %s", newSrcPwd) return 1 } @@ -83,7 +82,7 @@ func (cmd *CopyCommand) copySecret(source string, target string) error { return err } - log.Info("Copied %s to %s", source, target) + log.UserDebug("Copied %s to %s", source, target) return nil } diff --git a/cli/grep.go b/cli/grep.go index 687c84d9..458faa6b 100644 --- a/cli/grep.go +++ b/cli/grep.go @@ -54,10 +54,14 @@ func (cmd *GrepCommand) IsSane() bool { return cmd.Path != "" && cmd.Search != "" } +// PrintUsage print command usage +func (cmd *GrepCommand) PrintUsage() { + log.UserInfo("Usage:\ngrep ") +} + // Parse given arguments and return status func (cmd *GrepCommand) Parse(args []string) error { if len(args) != 3 { - fmt.Println("Usage:\ngrep ") return fmt.Errorf("cannot parse arguments") } cmd.Search = args[1] @@ -68,7 +72,7 @@ func (cmd *GrepCommand) Parse(args []string) error { // Run executes 'grep' with given RemoveCommand's parameters func (cmd *GrepCommand) Run() int { path := cmdPath(cmd.client.Pwd, cmd.Path) - filePaths := []string{} + var filePaths []string switch t := cmd.client.GetType(path); t { case client.LEAF: @@ -78,7 +82,7 @@ func (cmd *GrepCommand) Run() int { filePaths = append(filePaths, traversedPath) } default: - log.NotAValidPath(path) + log.UserError("Not a valid path for operation: %s", path) return 1 } diff --git a/cli/ls.go b/cli/ls.go index c48ffeda..8e79cd93 100644 --- a/cli/ls.go +++ b/cli/ls.go @@ -2,7 +2,6 @@ package cli import ( "fmt" - "io" "strings" "github.com/fishi0x01/vsh/client" @@ -14,18 +13,14 @@ type ListCommand struct { name string client *client.Client - stderr io.Writer - stdout io.Writer Path string } // NewListCommand creates a new ListCommand parameter container -func NewListCommand(c *client.Client, stdout io.Writer, stderr io.Writer) *ListCommand { +func NewListCommand(c *client.Client) *ListCommand { return &ListCommand{ name: "ls", client: c, - stdout: stdout, - stderr: stderr, } } @@ -39,6 +34,11 @@ func (cmd *ListCommand) IsSane() bool { return cmd.Path != "" } +// PrintUsage print command usage +func (cmd *ListCommand) PrintUsage() { + log.UserInfo("Usage:\nls ") +} + // Parse given arguments and return status func (cmd *ListCommand) Parse(args []string) error { if len(args) == 2 { @@ -46,7 +46,6 @@ func (cmd *ListCommand) Parse(args []string) error { } else if len(args) == 1 { cmd.Path = cmd.client.Pwd } else { - fmt.Println("Usage:\nls ") return fmt.Errorf("cannot parse arguments") } return nil @@ -58,9 +57,9 @@ func (cmd *ListCommand) Run() int { result, err := cmd.client.List(newPwd) if err != nil { - log.NotAValidPath(newPwd) + log.UserError("Not a valid path for operation: %s", newPwd) return 1 } - fmt.Fprintln(cmd.stdout, strings.Join(result, "\n")) + log.UserInfo(strings.Join(result, "\n")) return 0 } diff --git a/cli/mv.go b/cli/mv.go index 5aa95cef..3bd2dfc2 100644 --- a/cli/mv.go +++ b/cli/mv.go @@ -2,7 +2,6 @@ package cli import ( "fmt" - "io" "path/filepath" "github.com/fishi0x01/vsh/client" @@ -14,19 +13,15 @@ type MoveCommand struct { name string client *client.Client - stderr io.Writer - stdout io.Writer Source string Target string } // NewMoveCommand creates a new MoveCommand parameter container -func NewMoveCommand(c *client.Client, stdout io.Writer, stderr io.Writer) *MoveCommand { +func NewMoveCommand(c *client.Client) *MoveCommand { return &MoveCommand{ name: "mv", client: c, - stdout: stdout, - stderr: stderr, } } @@ -40,10 +35,14 @@ func (cmd *MoveCommand) IsSane() bool { return cmd.Source != "" && cmd.Target != "" } +// PrintUsage print command usage +func (cmd *MoveCommand) PrintUsage() { + log.UserInfo("Usage:\nmv ") +} + // Parse given arguments and return status func (cmd *MoveCommand) Parse(args []string) error { if len(args) != 3 { - fmt.Println("Usage:\nmv ") return fmt.Errorf("cannot parse arguments") } cmd.Source = args[1] @@ -62,7 +61,7 @@ func (cmd *MoveCommand) Run() int { case client.NODE: runCommandWithTraverseTwoPaths(cmd.client, newSrcPwd, newTargetPwd, cmd.moveSecret) default: - log.NotAValidPath(newSrcPwd) + log.UserError("Not a valid path for operation: %s", newSrcPwd) return 1 } @@ -88,7 +87,7 @@ func (cmd *MoveCommand) moveSecret(source string, target string) error { return err } - log.Info("Moved %s to %s", source, target) + log.UserDebug("Moved %s to %s", source, target) return nil } diff --git a/cli/rm.go b/cli/rm.go index ced6cc78..458b0965 100644 --- a/cli/rm.go +++ b/cli/rm.go @@ -2,8 +2,6 @@ package cli import ( "fmt" - "io" - "github.com/fishi0x01/vsh/client" "github.com/fishi0x01/vsh/log" ) @@ -13,18 +11,14 @@ type RemoveCommand struct { name string client *client.Client - stderr io.Writer - stdout io.Writer Path string } // NewRemoveCommand creates a new RemoveCommand parameter container -func NewRemoveCommand(c *client.Client, stdout io.Writer, stderr io.Writer) *RemoveCommand { +func NewRemoveCommand(c *client.Client) *RemoveCommand { return &RemoveCommand{ name: "rm", client: c, - stdout: stdout, - stderr: stderr, } } @@ -38,10 +32,14 @@ func (cmd *RemoveCommand) IsSane() bool { return cmd.Path != "" } +// PrintUsage print command usage +func (cmd *RemoveCommand) PrintUsage() { + log.UserInfo("Usage:\nrm ") +} + // Parse given arguments and return status func (cmd *RemoveCommand) Parse(args []string) error { if len(args) != 2 { - fmt.Println("Usage:\nrm ") return fmt.Errorf("cannot parse arguments") } cmd.Path = args[1] @@ -63,7 +61,7 @@ func (cmd *RemoveCommand) Run() int { } } default: - log.NotAValidPath(newPwd) + log.UserError("Not a valid path for operation: %s", newPwd) return 1 } @@ -77,7 +75,7 @@ func (cmd *RemoveCommand) removeSecret(path string) error { return err } - log.Info("Removed %s", path) + log.UserDebug("Removed %s", path) return nil } diff --git a/client/client.go b/client/client.go index 7c8c3d6a..83ada1ee 100644 --- a/client/client.go +++ b/client/client.go @@ -65,10 +65,11 @@ func NewClient(conf *VaultConfig) (*Client, error) { if sliceContains(permissions, "list") || sliceContains(permissions, "root") { mounts, err = vault.Sys().ListMounts() } else { - log.Debug("Cannot auto-discover mount backends: Token does not have list permission on sys/mounts") + log.UserDebug("Cannot auto-discover mount backends: Token does not have list permission on sys/mounts") } if err != nil { + log.AppTrace("%+v", err) return nil, err } @@ -80,7 +81,7 @@ func NewClient(conf *VaultConfig) (*Client, error) { return nil, err } backends[path] = v - log.Debug("Found KV backend '%v' with version '%v'", path, v) + log.UserDebug("Found KV backend '%v' with version '%v'", path, v) } } diff --git a/client/delete.go b/client/delete.go index bb7b87cb..3dca6488 100644 --- a/client/delete.go +++ b/client/delete.go @@ -2,6 +2,7 @@ package client import ( "errors" + "github.com/fishi0x01/vsh/log" ) func (client *Client) topLevelDelete(path string) error { @@ -10,5 +11,8 @@ func (client *Client) topLevelDelete(path string) error { func (client *Client) lowLevelDelete(path string) (err error) { _, err = client.Vault.Logical().Delete(client.getKVMetaDataPath(path)) + if err != nil { + log.AppTrace("%+v", err) + } return err } diff --git a/client/list.go b/client/list.go index d8449b2e..1db265c5 100644 --- a/client/list.go +++ b/client/list.go @@ -2,6 +2,7 @@ package client import ( "errors" + "github.com/fishi0x01/vsh/log" ) func (client *Client) listTopLevel() (result []string) { @@ -19,6 +20,7 @@ func (client *Client) listLowLevel(path string) (result []string, err error) { s, err := client.Vault.Logical().List(client.getKVMetaDataPath(path)) if err != nil { + log.AppTrace("%+v", err) return result, err } diff --git a/client/read.go b/client/read.go index af5660c8..d12c2eb5 100644 --- a/client/read.go +++ b/client/read.go @@ -2,6 +2,7 @@ package client import ( "errors" + "github.com/fishi0x01/vsh/log" "github.com/hashicorp/vault/api" ) @@ -12,5 +13,8 @@ func (client *Client) topLevelRead(path string) (secret *api.Secret, err error) func (client *Client) lowLevelRead(path string) (secret *api.Secret, err error) { secret, err = client.Vault.Logical().Read(client.getKVDataPath(path)) + if err != nil { + log.AppTrace("%+v", err) + } return secret, err } diff --git a/client/traverse.go b/client/traverse.go index 8dcd49a0..de6c8eac 100644 --- a/client/traverse.go +++ b/client/traverse.go @@ -16,7 +16,7 @@ func (client *Client) topLevelTraverse(path string) (result []string) { func (client *Client) lowLevelTraverse(path string) (result []string) { s, err := client.Vault.Logical().List(client.getKVMetaDataPath(path)) if err != nil { - log.Error("Error traversing path: %v", err) + log.AppTrace("%+v", err) return nil } diff --git a/client/write.go b/client/write.go index 7a46a011..1118f761 100644 --- a/client/write.go +++ b/client/write.go @@ -2,6 +2,7 @@ package client import ( "errors" + "github.com/fishi0x01/vsh/log" "github.com/hashicorp/vault/api" ) @@ -23,5 +24,8 @@ func (client *Client) lowLevelWrite(path string, secret *api.Secret) (err error) } _, err = client.Vault.Logical().Write(client.getKVDataPath(path), secret.Data) + if err != nil { + log.AppTrace("%+v", err) + } return err } diff --git a/completer/completer.go b/completer/completer.go index bc4a0367..634a5b7e 100644 --- a/completer/completer.go +++ b/completer/completer.go @@ -1,7 +1,7 @@ package completer import ( - "fmt" + "github.com/fishi0x01/vsh/log" "strings" "github.com/c-bata/go-prompt" @@ -25,7 +25,7 @@ func NewCompleter(client *client.Client, disableAutoCompletion bool) *Completer // TogglePathCompletion enable/disable path auto-completion func (c *Completer) TogglePathCompletion() { c.pathCompletionToggle = !c.pathCompletionToggle - fmt.Printf("Use path auto-completion: %t\n", c.pathCompletionToggle) + log.UserInfo("Use path auto-completion: %t", c.pathCompletionToggle) } func (c *Completer) getAbsoluteTopLevelSuggestions() []prompt.Suggest { diff --git a/log/log.go b/log/log.go index d9eb28f7..eccded25 100644 --- a/log/log.go +++ b/log/log.go @@ -4,6 +4,7 @@ import ( "fmt" au "github.com/logrusorgru/aurora" "log" + "os" "path/filepath" "runtime" "strconv" @@ -16,77 +17,127 @@ const ( errorLvl ) -var verbose = false +var verbosityLevel int -// Init initializes the logger -func Init() { - log.SetFlags(0) -} +var ( + appDebug *log.Logger + appInfo *log.Logger + appWarning *log.Logger + appError *log.Logger -// ToggleVerbose toggles the verbose mode -func ToggleVerbose() { - verbose = !verbose -} + userDebug *log.Logger + userInfo *log.Logger + userError *log.Logger +) -func logger(level uint, f string, args ...interface{}) { - _, fi, line, _ := runtime.Caller(2) - loc := filepath.Base(fi) + ":" + strconv.Itoa(line) + " " - var prefix, message au.Value - - switch level { - case debugLvl: - prefix = au.Cyan("[DEBUG] " + loc) - message = au.Cyan(au.Sprintf(f, args...)) - case infoLvl: - prefix = au.Green("[INFO] " + loc) - message = au.Green(au.Sprintf(f, args...)) - case warnLvl: - prefix = au.Yellow("[WARN] " + loc) - message = au.Yellow(au.Sprintf(f, args...)) - case errorLvl: - prefix = au.Red("[ERROR] " + loc) - message = au.Red(au.Sprintf(f, args...)) +// Init initialize the log with given verbosity level +func Init(verbosity string) error { + switch verbosity { + case "DEBUG": + verbosityLevel = debugLvl + case "INFO": + verbosityLevel = infoLvl + case "WARN": + verbosityLevel = warnLvl + case "ERROR": + verbosityLevel = errorLvl default: - panic("Cannot log!") + fmt.Printf("Not a valid verbosity level: %s\n", verbosity) + fmt.Println("Allowed values are DEBUG | INFO | WARN | ERROR") + return fmt.Errorf("not a valid verbosity level: %s", verbosity) + } + + if verbosityLevel <= debugLvl { + file, err := os.OpenFile("vsh_trace.log", os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0666) + if err != nil { + log.Fatal(err) + } + + appDebug = log.New(file, + "debugLvl: ", + log.Ldate|log.Ltime) + } + + if verbosityLevel <= infoLvl { + appInfo = log.New(os.Stdout, + "infoLvl: ", + log.Ldate|log.Ltime) + } + + if verbosityLevel <= warnLvl { + appWarning = log.New(os.Stdout, + "WARNING: ", + log.Ldate|log.Ltime) + } + + if verbosityLevel <= errorLvl { + appError = log.New(os.Stderr, + "errorLvl: ", + log.Ldate|log.Ltime) + } + + if verbosityLevel <= debugLvl { + userDebug = log.New(os.Stdout, "", 0) } - log.SetPrefix(au.Sprintf(au.Bold(prefix))) - log.Printf(au.Sprintf(message)) - log.SetPrefix("") + userInfo = log.New(os.Stdout, "", 0) + userError = log.New(os.Stderr, "", 0) + + return nil +} + +func getCustomPrefix(logger *log.Logger) string { + _, fi, line, _ := runtime.Caller(2) + loc := filepath.Base(fi) + ":" + strconv.Itoa(line) + return logger.Prefix() + loc + " " +} + +// AppTrace log application trace +func AppTrace(f string, args ...interface{}) { + if appDebug != nil { + appDebug.SetPrefix(getCustomPrefix(appDebug)) + appDebug.Printf(f, args...) + } } -// Debug writes debug message to log -func Debug(f string, args ...interface{}) { - if verbose { - logger(debugLvl, f, args...) +// AppInfo log application infoLvl +func AppInfo(f string, args ...interface{}) { + if appInfo != nil { + appInfo.SetPrefix(getCustomPrefix(appInfo)) + appInfo.Printf(f, args...) } } -// Info writes info message to log -func Info(f string, args ...interface{}) { - if verbose { - logger(infoLvl, f, args...) +// AppWarning log application warning +func AppWarning(f string, args ...interface{}) { + if appWarning != nil { + appWarning.SetPrefix(getCustomPrefix(appWarning)) + appWarning.Printf(f, args...) } } -// Warn writes warn message to log -func Warn(f string, args ...interface{}) { - logger(warnLvl, f, args...) +// AppError log application error +func AppError(f string, args ...interface{}) { + if appError != nil { + appError.SetPrefix(getCustomPrefix(appError)) + appError.Printf(f, args...) + } } -// Error writes error message to log -func Error(f string, args ...interface{}) { - logger(errorLvl, f, args...) +// UserDebug log user debugLvl +func UserDebug(f string, args ...interface{}) { + if userDebug != nil { + userDebug.Printf(f, args...) + } } -// NotAValidPath prints not a valid path message -func NotAValidPath(f string) { - message := au.Red(au.Sprintf("Not a valid path for operation: %s\n", f)) - fmt.Printf(au.Sprintf(message)) +// UserInfo log user infoLvl +func UserInfo(f string, args ...interface{}) { + userInfo.Printf(f, args...) } -// NotAValidCommand prints not a valid command -func NotAValidCommand(c string) { - message := au.Red(au.Sprintf("Not a valid command: %s\n", c)) - fmt.Printf(au.Sprintf(message)) +// UserError log user error +func UserError(f string, args ...interface{}) { + message := au.Red(au.Sprintf(f, args...)) + userError.Println(au.Sprintf(message)) } diff --git a/main.go b/main.go index c320aef9..6d89da9a 100644 --- a/main.go +++ b/main.go @@ -29,20 +29,20 @@ type commands struct { func newCommands(client *client.Client) *commands { return &commands{ - mv: cli.NewMoveCommand(client, os.Stdout, os.Stderr), - cp: cli.NewCopyCommand(client, os.Stdout, os.Stderr), - append: cli.NewAppendCommand(client, os.Stdout, os.Stderr), - rm: cli.NewRemoveCommand(client, os.Stdout, os.Stderr), - ls: cli.NewListCommand(client, os.Stdout, os.Stderr), - cd: cli.NewCdCommand(client, os.Stdout, os.Stderr), - cat: cli.NewCatCommand(client, os.Stdout, os.Stderr), + mv: cli.NewMoveCommand(client), + cp: cli.NewCopyCommand(client), + append: cli.NewAppendCommand(client), + rm: cli.NewRemoveCommand(client), + ls: cli.NewListCommand(client), + cd: cli.NewCdCommand(client), + cat: cli.NewCatCommand(client), grep: cli.NewGrepCommand(client, os.Stdout, os.Stderr), } } var ( vshVersion = "" - verbose = false + verbosity = "INFO" isInteractive = true ) @@ -89,6 +89,10 @@ func executor(in string) { cmd, err = getCommand(args, commands) } + if err != nil && cmd != nil { + cmd.PrintUsage() + } + if err != nil && !isInteractive { os.Exit(1) } @@ -128,7 +132,7 @@ func getCommand(args []string, commands *commands) (cmd cli.Command, err error) err = commands.grep.Parse(args) cmd = commands.grep default: - log.NotAValidCommand(args[0]) + log.UserError("Not a valid command: %s", args[0]) return nil, fmt.Errorf("not a valid command") } return cmd, err @@ -151,30 +155,30 @@ func getVaultToken() (token string, err error) { } func main() { - log.Init() - var cmdString string var hasVersion bool var disableAutoCompletion bool flag.StringVar(&cmdString, "c", "", "command to run") flag.BoolVar(&hasVersion, "version", false, "print vsh version") flag.BoolVar(&disableAutoCompletion, "disable-auto-completion", false, "disable auto-completion on paths") - flag.BoolVar(&verbose, "v", false, "verbose output") + flag.StringVar(&verbosity, "v", "INFO", "DEBUG | INFO | WARN | ERROR - debug option creates vsh_trace.log") flag.Parse() + var err error + err = log.Init(verbosity) + if err != nil { + os.Exit(1) + } + if hasVersion { printVersion() return } - if verbose { - log.ToggleVerbose() - } - token, ve := getVaultToken() if ve != nil { - log.Error("Error getting vault token") - log.Error("%v", ve) + log.AppError("Error getting vault token") + log.AppError("%v", ve) return } @@ -183,11 +187,11 @@ func main() { Token: token, StartPath: os.Getenv("VAULT_PATH"), } - var err error + vaultClient, err = client.NewClient(conf) if err != nil { - log.Error("Error initializing vault client | Is VAULT_ADDR properly set? Do you provide a proper token?") - log.Error("%v", err) + log.UserError("Error initializing vault client | Is VAULT_ADDR properly set? Do you provide a proper token?") + log.UserError("%v", err) os.Exit(1) } diff --git a/test/run.sh b/test/run.sh index f85d1985..c1fd62bc 100755 --- a/test/run.sh +++ b/test/run.sh @@ -1,7 +1,7 @@ #!/bin/bash set -e # required to fail test suite when a single test fails -VAULT_VERSIONS=("1.5.3" "1.0.0") +VAULT_VERSIONS=("1.5.4" "1.0.0") KV_BACKENDS=("KV1" "KV2") DIR="$( cd "$( dirname "${BASH_SOURCE[0]}" )" >/dev/null 2>&1 && pwd )" diff --git a/test/suites/commands/ls.bats b/test/suites/commands/ls.bats index d4a70231..b62b86f3 100644 --- a/test/suites/commands/ls.bats +++ b/test/suites/commands/ls.bats @@ -28,7 +28,7 @@ load ../../bin/plugins/bats-assert/load ####################################### echo "==== case: list backends with reduced permissions ====" - run bash -c "VAULT_TOKEN=no-root ${APP_BIN} -v -c 'ls /'" + run bash -c "VAULT_TOKEN=no-root ${APP_BIN} -v DEBUG -c 'ls /'" assert_success assert_output --partial "Cannot auto-discover mount backends" diff --git a/test/suites/edge-cases/logging.bats b/test/suites/edge-cases/logging.bats new file mode 100644 index 00000000..c000c3f8 --- /dev/null +++ b/test/suites/edge-cases/logging.bats @@ -0,0 +1,33 @@ +load ../../util/util +load ../../bin/plugins/bats-support/load +load ../../bin/plugins/bats-assert/load +load ../../bin/plugins/bats-file/load + +@test "vault-${VAULT_VERSION} - logging" { + ####################################### + echo "==== case: default verbosity ====" + run bash -c "VAULT_TOKEN=delete-only ${APP_BIN} -c 'ls /KV2/src/a'" + assert_success + assert_line "foo" + assert_line "foo/" + assert_file_not_exist vsh_trace.log + + echo "==== case: print debug info for user ====" + run bash -c "VAULT_TOKEN=delete-only ${APP_BIN} -v DEBUG -c 'ls /KV2/src/a'" + assert_success + assert_line "Cannot auto-discover mount backends: Token does not have list permission on sys/mounts" + assert_line "foo" + assert_line "foo/" + assert_file_exist vsh_trace.log + + echo "==== case: invalid verbosity level ====" + run bash -c "VAULT_TOKEN=delete-only ${APP_BIN} -v NOTEXIST -c 'ls /KV2/src/a'" + assert_failure 1 + assert_line --partial "Not a valid verbosity level" + + echo "==== case: login with false token ====" + run bash -c "VAULT_TOKEN=false ${APP_BIN} -v DEBUG -c 'ls /KV2/src/a'" + assert_failure 1 + run cat vsh_trace.log + assert_line --partial "* permission denied" +} diff --git a/test/suites/edge-cases/params.bats b/test/suites/edge-cases/params.bats index ea4299ac..3fdfed9d 100644 --- a/test/suites/edge-cases/params.bats +++ b/test/suites/edge-cases/params.bats @@ -5,17 +5,17 @@ load ../../bin/plugins/bats-assert/load @test "vault-${VAULT_VERSION} whitespaces between parameters" { ####################################### echo "==== case: copy with multiple whitespaces ====" - run ${APP_BIN} -v -c "cp /KV2/src/prod/all /KV2/dest/prod/all" + run ${APP_BIN} -v DEBUG -c "cp /KV2/src/prod/all /KV2/dest/prod/all" assert_success assert_output --partial "Copied /KV2/src/prod/all to /KV2/dest/prod/all" echo "==== case: copy with tabs ====" - run ${APP_BIN} -v -c "cp /KV2/src/prod/all /KV2/dest/prod/all " + run ${APP_BIN} -v DEBUG -c "cp /KV2/src/prod/all /KV2/dest/prod/all " assert_success assert_output --partial "Copied /KV2/src/prod/all to /KV2/dest/prod/all" echo "==== case: append with multiple whitespaces ====" - run ${APP_BIN} -v -c "append --rename /KV2/src/prod/all /KV2/dest/prod/all" + run ${APP_BIN} -v DEBUG -c "append --rename /KV2/src/prod/all /KV2/dest/prod/all" assert_success assert_output --partial "Appended values from /KV2/src/prod/all to /KV2/dest/prod/all" } diff --git a/test/util/util.bash b/test/util/util.bash index be93ae95..3a492ef1 100755 --- a/test/util/util.bash +++ b/test/util/util.bash @@ -14,6 +14,7 @@ export APP_BIN="${DIR}/../../build/vsh_${UNAME}_amd64" export NO_VALUE_FOUND="No value found at" setup() { + rm -f vsh_trace.log docker run -d \ --name=${VAULT_CONTAINER_NAME} \ -p "${VAULT_HOST_PORT}:8200" \