From c3241a1513a433152525a497d623f485b0f47d91 Mon Sep 17 00:00:00 2001 From: Kemal Hadimli Date: Thu, 7 Apr 2022 13:42:03 +0100 Subject: [PATCH 1/5] fix: Include all responses in log Fixes #571. --- cmd/root.go | 5 +++++ internal/logging/logger.go | 2 +- pkg/ui/console/client.go | 30 ++++++++++++------------------ pkg/ui/console/policy.go | 2 +- pkg/ui/console/progress.go | 6 ++++-- pkg/ui/output.go | 23 +++++++++++++++++------ 6 files changed, 40 insertions(+), 28 deletions(-) diff --git a/cmd/root.go b/cmd/root.go index fac786bdda6d9a..0a1ae6d81eff77 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -6,6 +6,7 @@ import ( "strings" "github.com/cloudquery/cloudquery/pkg/client" + "github.com/cloudquery/cloudquery/pkg/ui" "github.com/thoas/go-funk" @@ -163,5 +164,9 @@ func initLogging() { if funk.ContainsString(os.Args, "completion") { return } + if !ui.IsTerminal() { + loggerConfig.ConsoleLoggingEnabled = true // always true when no terminal + } + zerolog.Logger = logging.Configure(loggerConfig) } diff --git a/internal/logging/logger.go b/internal/logging/logger.go index 207c62f664fd9f..3bdb01f7fa24d1 100644 --- a/internal/logging/logger.go +++ b/internal/logging/logger.go @@ -53,7 +53,7 @@ type Config struct { func Configure(config Config) zerolog.Logger { var writers []io.Writer - if config.ConsoleLoggingEnabled || !ui.IsTerminal() { + if config.ConsoleLoggingEnabled { if config.EncodeLogsAsJson { writers = append(writers, zerolog.ConsoleWriter{FormatLevel: formatLevel(config.ConsoleNoColor), Out: os.Stdout, NoColor: config.ConsoleNoColor}) } else { diff --git a/pkg/ui/console/client.go b/pkg/ui/console/client.go index 17ed55a3a91c8f..d8c50f4a037858 100644 --- a/pkg/ui/console/client.go +++ b/pkg/ui/console/client.go @@ -125,13 +125,11 @@ func (c Client) DownloadProviders(ctx context.Context) error { ui.ColorizedOutput(ui.ColorProgress, "Initializing CloudQuery Providers...\n\n") err := c.c.DownloadProviders(ctx) if err != nil { - time.Sleep(100 * time.Millisecond) + ui.SleepBeforeError(ctx) ui.ColorizedOutput(ui.ColorError, "❌ Failed to initialize provider: %s.\n\n", err.Error()) return err } - // sleep some extra 500 milliseconds for progress refresh - if ui.IsTerminal() { - time.Sleep(500 * time.Millisecond) + if c.updater != nil { c.updater.Wait() } ui.ColorizedOutput(ui.ColorProgress, "Finished provider initialization...\n\n") @@ -175,11 +173,11 @@ func (c Client) Fetch(ctx context.Context, failOnError bool) error { } } - if ui.IsTerminal() && fetchProgress != nil { + if fetchProgress != nil { fetchProgress.MarkAllDone() fetchProgress.Wait() - printFetchResponse(response, viper.GetBool("redact-diags"), viper.GetBool("verbose")) } + printFetchResponse(response, viper.GetBool("redact-diags"), viper.GetBool("verbose")) if response == nil { ui.ColorizedOutput(ui.ColorProgress, "Provider fetch canceled.\n\n") @@ -215,13 +213,11 @@ func (c Client) DownloadPolicy(ctx context.Context, args []string) error { ui.ColorizedOutput(ui.ColorProgress, "Downloading CloudQuery Policy...\n") p, err := c.c.LoadPolicy(ctx, "policy", args[0]) if err != nil { - time.Sleep(100 * time.Millisecond) + ui.SleepBeforeError(ctx) ui.ColorizedOutput(ui.ColorError, "❌ Failed to Download policy: %s.\n\n", err.Error()) return err } - // sleep some extra 300 milliseconds for progress refresh - if ui.IsTerminal() { - time.Sleep(300 * time.Millisecond) + if c.updater != nil { c.updater.Wait() } ui.ColorizedOutput(ui.ColorProgress, "Finished downloading policy...\n") @@ -266,18 +262,16 @@ func (c Client) RunPolicies(ctx context.Context, policySource, outputDir string, } results, err := c.c.RunPolicies(ctx, req) - if ui.IsTerminal() && policyRunProgress != nil { + if policyRunProgress != nil { policyRunProgress.MarkAllDone() - // sleep some extra 500 milliseconds for progress refresh - time.Sleep(500 * time.Millisecond) policyRunProgress.Wait() - if !noResults { - printPolicyResponse(results) - } + } + if !noResults { + printPolicyResponse(results) } if err != nil { - time.Sleep(100 * time.Millisecond) + ui.SleepBeforeError(ctx) ui.ColorizedOutput(ui.ColorError, "❌ Failed to run policies: %s.\n\n", err.Error()) return err } @@ -365,7 +359,7 @@ func (c Client) CallModule(ctx context.Context, req ModuleCallRequest) error { } out, err := c.c.ExecuteModule(ctx, runReq) if err != nil { - time.Sleep(100 * time.Millisecond) + ui.SleepBeforeError(ctx) ui.ColorizedOutput(ui.ColorError, "❌ Failed to execute module: %s.\n\n", err.Error()) return err } else if out == nil { diff --git a/pkg/ui/console/policy.go b/pkg/ui/console/policy.go index b018bba5f6f19f..f03d92df8f422a 100644 --- a/pkg/ui/console/policy.go +++ b/pkg/ui/console/policy.go @@ -69,7 +69,7 @@ func getNestedPolicyExample(p *policy.Policy, policyPath string) string { } func printPolicyResponse(results []*policy.ExecutionResult) { - if results == nil { + if len(results) == 0 { return } for _, execResult := range results { diff --git a/pkg/ui/console/progress.go b/pkg/ui/console/progress.go index 0e764df5338861..3f6675047ff6a5 100644 --- a/pkg/ui/console/progress.go +++ b/pkg/ui/console/progress.go @@ -147,7 +147,7 @@ func (u *Progress) AttachReader(name string, data io.Reader) io.Reader { } func (u *Progress) Wait() { - time.Sleep(100 * time.Millisecond) + time.Sleep(600 * time.Millisecond) u.p.Wait() fmt.Println() } @@ -168,7 +168,9 @@ func (u *Progress) AbortAll() { for _, b := range u.bars { b.b.Abort(true) } - u.Wait() + time.Sleep(100 * time.Millisecond) + u.p.Wait() + fmt.Println() } func (u *Progress) MarkAllDone() { diff --git a/pkg/ui/output.go b/pkg/ui/output.go index c20f50745edf9b..77eae3521ee322 100644 --- a/pkg/ui/output.go +++ b/pkg/ui/output.go @@ -1,9 +1,11 @@ package ui import ( + "context" "fmt" "os" "strings" + "time" "github.com/fatih/color" "github.com/mattn/go-isatty" @@ -15,21 +17,30 @@ import ( // ColorizedOutput outputs a colored message directly to the terminal. // The remaining arguments should be interpolations for the format string. func ColorizedOutput(c *color.Color, msg string, values ...interface{}) { - if !IsTerminal() { + if viper.GetBool("enable-console-log") { // Print output to log - log.Info().Msgf(strings.ReplaceAll(msg, "\n", ""), values...) - return + if logMsg := strings.ReplaceAll(msg, "\n", ""); logMsg != "" { + log.Info().Msgf(logMsg, values...) + } } _, _ = c.Printf(msg, values...) } func IsTerminal() bool { - if viper.GetBool("enable-console-log") { - return false - } return isatty.IsTerminal(os.Stdout.Fd()) && term.IsTerminal(int(os.Stdout.Fd())) } +func SleepBeforeError(ctx context.Context) { + if !IsTerminal() { + return + } + + select { + case <-ctx.Done(): + case <-time.After(100 * time.Millisecond): + } +} + func Colorize(c *color.Color, noColor bool, msg string, values ...interface{}) string { if noColor { return fmt.Sprintf(msg, values...) From fd3c5caa685cf30f305197e5c52653178517bc09 Mon Sep 17 00:00:00 2001 From: Kemal Hadimli Date: Thu, 7 Apr 2022 14:08:42 +0100 Subject: [PATCH 2/5] No progress if console log, no regular prints either --- pkg/ui/console/client.go | 34 ++++++++++++++++++---------------- pkg/ui/output.go | 5 +++++ 2 files changed, 23 insertions(+), 16 deletions(-) diff --git a/pkg/ui/console/client.go b/pkg/ui/console/client.go index d8c50f4a037858..6c85c25390779f 100644 --- a/pkg/ui/console/client.go +++ b/pkg/ui/console/client.go @@ -62,16 +62,17 @@ func CreateClient(ctx context.Context, configPath string, configMutator func(*co } func CreateClientFromConfig(ctx context.Context, cfg *config.Config, opts ...client.Option) (*Client, error) { - progressUpdater := NewProgress(ctx, func(o *ProgressOptions) { - o.AppendDecorators = []decor.Decorator{decor.Percentage()} - }) + var progressUpdater *Progress + if ui.DoProgress() { + progressUpdater = NewProgress(ctx, func(o *ProgressOptions) { + o.AppendDecorators = []decor.Decorator{decor.Percentage()} + }) + } if cfg.CloudQuery.Connection == nil { return nil, errors.New("connection configuration is not set") } opts = append(opts, func(c *client.Client) { - if ui.IsTerminal() { - c.HubProgressUpdater = progressUpdater - } + c.HubProgressUpdater = progressUpdater c.Providers = cfg.CloudQuery.Providers c.NoVerify = viper.GetBool("no-verify") c.PluginDirectory = cfg.CloudQuery.PluginDirectory @@ -92,15 +93,16 @@ func CreateClientFromConfig(ctx context.Context, cfg *config.Config, opts ...cli } func CreateNullClient(ctx context.Context, opts ...client.Option) (*Client, error) { - progressUpdater := NewProgress(ctx, func(o *ProgressOptions) { - o.AppendDecorators = []decor.Decorator{decor.Percentage()} - }) + var progressUpdater *Progress + if ui.DoProgress() { + progressUpdater = NewProgress(ctx, func(o *ProgressOptions) { + o.AppendDecorators = []decor.Decorator{decor.Percentage()} + }) + } opts = append(opts, func(c *client.Client) { - if ui.IsTerminal() { - c.HubProgressUpdater = progressUpdater - c.PluginDirectory = "./.cq/providers" - c.PolicyDirectory = "./.cq/policies" - } + c.HubProgressUpdater = progressUpdater + c.PluginDirectory = "./.cq/providers" + c.PolicyDirectory = "./.cq/policies" }) c, err := client.New(ctx, opts...) if err != nil { @@ -157,7 +159,7 @@ func (c Client) Fetch(ctx context.Context, failOnError bool) error { var fetchProgress *Progress var fetchCallback client.FetchUpdateCallback - if ui.IsTerminal() { + if ui.DoProgress() { fetchProgress, fetchCallback = buildFetchProgress(ctx, c.cfg.Providers) } request := client.FetchRequest{ @@ -251,7 +253,7 @@ func (c Client) RunPolicies(ctx context.Context, policySource, outputDir string, var policyRunCallback policy.UpdateCallback // if we are running in a terminal, build the progress bar - if ui.IsTerminal() { + if ui.DoProgress() { policyRunProgress, policyRunCallback = buildPolicyRunProgress(ctx, policiesToRun) } // Policies run request diff --git a/pkg/ui/output.go b/pkg/ui/output.go index 77eae3521ee322..81e491fc36a2a6 100644 --- a/pkg/ui/output.go +++ b/pkg/ui/output.go @@ -22,6 +22,7 @@ func ColorizedOutput(c *color.Color, msg string, values ...interface{}) { if logMsg := strings.ReplaceAll(msg, "\n", ""); logMsg != "" { log.Info().Msgf(logMsg, values...) } + return } _, _ = c.Printf(msg, values...) } @@ -30,6 +31,10 @@ func IsTerminal() bool { return isatty.IsTerminal(os.Stdout.Fd()) && term.IsTerminal(int(os.Stdout.Fd())) } +func DoProgress() bool { + return IsTerminal() && !viper.GetBool("enable-console-log") +} + func SleepBeforeError(ctx context.Context) { if !IsTerminal() { return From 770b9161854850aaca29277a7abcc1dde5ae5ee3 Mon Sep 17 00:00:00 2001 From: Kemal Hadimli Date: Thu, 7 Apr 2022 14:42:53 +0100 Subject: [PATCH 3/5] Get rid of typed nil --- pkg/ui/console/client.go | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/pkg/ui/console/client.go b/pkg/ui/console/client.go index 6c85c25390779f..271baf516d50d3 100644 --- a/pkg/ui/console/client.go +++ b/pkg/ui/console/client.go @@ -43,7 +43,7 @@ import ( type Client struct { c *client.Client cfg *config.Config - updater *Progress + updater ui.Progress } func CreateClient(ctx context.Context, configPath string, configMutator func(*config.Config) error, opts ...client.Option) (*Client, error) { @@ -62,7 +62,7 @@ func CreateClient(ctx context.Context, configPath string, configMutator func(*co } func CreateClientFromConfig(ctx context.Context, cfg *config.Config, opts ...client.Option) (*Client, error) { - var progressUpdater *Progress + var progressUpdater ui.Progress if ui.DoProgress() { progressUpdater = NewProgress(ctx, func(o *ProgressOptions) { o.AppendDecorators = []decor.Decorator{decor.Percentage()} @@ -93,7 +93,7 @@ func CreateClientFromConfig(ctx context.Context, cfg *config.Config, opts ...cli } func CreateNullClient(ctx context.Context, opts ...client.Option) (*Client, error) { - var progressUpdater *Progress + var progressUpdater ui.Progress if ui.DoProgress() { progressUpdater = NewProgress(ctx, func(o *ProgressOptions) { o.AppendDecorators = []decor.Decorator{decor.Percentage()} @@ -156,7 +156,7 @@ func (c Client) Fetch(ctx context.Context, failOnError bool) error { return err } ui.ColorizedOutput(ui.ColorProgress, "Starting provider fetch...\n\n") - var fetchProgress *Progress + var fetchProgress ui.Progress var fetchCallback client.FetchUpdateCallback if ui.DoProgress() { @@ -249,7 +249,7 @@ func (c Client) RunPolicies(ctx context.Context, policySource, outputDir string, ui.ColorizedOutput(ui.ColorProgress, "Starting policies run...\n\n") - var policyRunProgress *Progress + var policyRunProgress ui.Progress var policyRunCallback policy.UpdateCallback // if we are running in a terminal, build the progress bar From 566865ed9822b90cbe1ce080277ae5f2d3600f4f Mon Sep 17 00:00:00 2001 From: Kemal Hadimli Date: Thu, 7 Apr 2022 15:40:53 +0100 Subject: [PATCH 4/5] Log invocation params --- cmd/root.go | 24 ++++++++++++++++++++---- cmd/util.go | 3 ++- 2 files changed, 22 insertions(+), 5 deletions(-) diff --git a/cmd/root.go b/cmd/root.go index 0a1ae6d81eff77..e8164c5c2bacc2 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -5,16 +5,15 @@ import ( "os" "strings" + "github.com/cloudquery/cloudquery/internal/logging" "github.com/cloudquery/cloudquery/pkg/client" "github.com/cloudquery/cloudquery/pkg/ui" - "github.com/thoas/go-funk" - - "github.com/cloudquery/cloudquery/internal/logging" - zerolog "github.com/rs/zerolog/log" "github.com/spf13/cobra" + "github.com/spf13/pflag" "github.com/spf13/viper" + "github.com/thoas/go-funk" ) // This is copied from https://github.com/spf13/cobra/blob/master/command.go#L491 @@ -170,3 +169,20 @@ func initLogging() { zerolog.Logger = logging.Configure(loggerConfig) } + +func logInvocationParams(cmd *cobra.Command, args []string) { + l := zerolog.Info() + rootCmd.Flags().Visit(func(f *pflag.Flag) { + if f.Name == "dsn" { + l = l.Str("pflag:"+f.Name, "(redacted)") + return + } + + l = l.Str("pflag:"+f.Name, f.Value.String()) + }) + cmd.Flags().Visit(func(f *pflag.Flag) { + l = l.Str("flag:"+f.Name, f.Value.String()) + }) + + l.Str("command", cmd.CommandPath()).Strs("args", args).Msg("Invocation parameters") +} diff --git a/cmd/util.go b/cmd/util.go index e7ca11c7d2ca10..d9fbadec301705 100644 --- a/cmd/util.go +++ b/cmd/util.go @@ -72,8 +72,9 @@ func handleCommand(f func(context.Context, *console.Client, *cobra.Command, []st } func handleConsole(ctx context.Context, tele *telemetry.Client, cmd *cobra.Command, args []string, f func(context.Context, *console.Client, *cobra.Command, []string) error) error { - cfgPath := viper.GetString("configPath") + logInvocationParams(cmd, args) + cfgPath := viper.GetString("configPath") ctx, _ = signalcontext.WithInterrupt(ctx, logging.NewZHcLog(&log.Logger, "")) var c *console.Client From ccf0e020911c1fc25b242ac97a720db04a7c64fb Mon Sep 17 00:00:00 2001 From: Kemal Hadimli Date: Thu, 7 Apr 2022 15:43:05 +0100 Subject: [PATCH 5/5] Also log version --- cmd/root.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/cmd/root.go b/cmd/root.go index e8164c5c2bacc2..8b6bf43e33e408 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -171,7 +171,7 @@ func initLogging() { } func logInvocationParams(cmd *cobra.Command, args []string) { - l := zerolog.Info() + l := zerolog.Info().Str("core_version", client.Version) rootCmd.Flags().Visit(func(f *pflag.Flag) { if f.Name == "dsn" { l = l.Str("pflag:"+f.Name, "(redacted)")