From 6c13bd7ac5adfce3569c6de4f2fac87e8e97ffc6 Mon Sep 17 00:00:00 2001 From: Mateusz Szostok Date: Thu, 13 Jul 2023 14:16:43 +0200 Subject: [PATCH] Remove logs scrolling while printing --- cmd/cli/cmd/install.go | 2 - go.mod | 4 +- helm/botkube/values.yaml | 4 +- internal/cli/install/config.go | 10 +- internal/cli/install/helm/install.go | 9 +- internal/cli/install/helm/status.go | 18 ++- internal/cli/install/install.go | 26 +++-- internal/cli/install/logs/json_parser.go | 29 ++--- internal/cli/install/logs/k8s.go | 3 - internal/cli/install/logs/printer.go | 140 +++++++---------------- internal/cli/printer/status.go | 14 +-- internal/kubex/wait.go | 5 +- 12 files changed, 101 insertions(+), 163 deletions(-) diff --git a/cmd/cli/cmd/install.go b/cmd/cli/cmd/install.go index c22399d3be..73e28433bf 100644 --- a/cmd/cli/cmd/install.go +++ b/cmd/cli/cmd/install.go @@ -47,8 +47,6 @@ func NewInstall() *cobra.Command { flags := installCmd.Flags() kubex.RegisterKubeconfigFlag(flags) - flags.BoolVar(&opts.LogsReportTimestamp, "logs-report-timestamp", false, "Print timestamp prefix to the Botkube logs entries") - flags.IntVar(&opts.LogsScrollingHeight, "logs-scrolling-height", 10, "") flags.DurationVar(&opts.Timeout, "timeout", 10*time.Minute, `Maximum time during which the Botkube installation is being watched, where "0" means "infinite". Valid time units are "ns", "us" (or "µs"), "ms", "s", "m", "h".`) flags.BoolVarP(&opts.Watch, "watch", "w", true, "Watches the status of the Botkube installation until it finish or the defined `--timeout` occurs.") diff --git a/go.mod b/go.mod index 44d3e41938..fc3ec49a33 100644 --- a/go.mod +++ b/go.mod @@ -11,6 +11,7 @@ require ( github.com/aws/aws-sdk-go v1.44.122 github.com/briandowns/spinner v1.23.0 github.com/bwmarrin/discordgo v0.25.0 + github.com/charmbracelet/log v0.2.2 github.com/dustin/go-humanize v1.0.1 github.com/fatih/color v1.13.0 github.com/go-playground/locales v0.14.0 @@ -34,6 +35,7 @@ require ( github.com/mattermost/mattermost-server/v6 v6.7.2 github.com/mattn/go-isatty v0.0.19 github.com/mattn/go-shellwords v1.0.12 + github.com/morikuni/aec v1.0.0 github.com/muesli/reflow v0.3.0 github.com/olivere/elastic v6.2.37+incompatible github.com/pkg/browser v0.0.0-20210911075715-681adbf594b8 @@ -95,7 +97,6 @@ require ( github.com/cespare/xxhash/v2 v2.2.0 // indirect github.com/chai2010/gettext-go v1.0.2 // indirect github.com/charmbracelet/lipgloss v0.7.1 // indirect - github.com/charmbracelet/log v0.2.2 // indirect github.com/containerd/containerd v1.7.0 // indirect github.com/cpuguy83/go-md2man/v2 v2.0.2 // indirect github.com/cyphar/filepath-securejoin v0.2.3 // indirect @@ -194,7 +195,6 @@ require ( github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd // indirect github.com/modern-go/reflect2 v1.0.2 // indirect github.com/monochromegane/go-gitignore v0.0.0-20200626010858-205db1a8cc00 // indirect - github.com/morikuni/aec v1.0.0 // indirect github.com/muesli/termenv v0.15.1 // indirect github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822 // indirect github.com/oklog/run v1.1.0 // indirect diff --git a/helm/botkube/values.yaml b/helm/botkube/values.yaml index b8b4db0cac..8ffbdd3682 100644 --- a/helm/botkube/values.yaml +++ b/helm/botkube/values.yaml @@ -828,8 +828,10 @@ settings: log: # -- Sets one of the log levels. Allowed values: `info`, `warn`, `debug`, `error`, `fatal`, `panic`. level: info - # -- If true, disable ANSI colors in logging. + # -- If true, disable ANSI colors in logging. Ignored when `json` formatter is used. disableColors: false + # -- Configures log format. Allowed values: `text`, `json`. + formatter: json # -- Botkube's system ConfigMap where internal data is stored. systemConfigMap: diff --git a/internal/cli/install/config.go b/internal/cli/install/config.go index 42176341dd..5bbcf62e40 100644 --- a/internal/cli/install/config.go +++ b/internal/cli/install/config.go @@ -25,10 +25,8 @@ const ( // Config holds parameters for Botkube installation on cluster. type Config struct { - Kubeconfig string - HelmParams helm.Config - LogsReportTimestamp bool - LogsScrollingHeight int - Watch bool - Timeout time.Duration + Kubeconfig string + HelmParams helm.Config + Watch bool + Timeout time.Duration } diff --git a/internal/cli/install/helm/install.go b/internal/cli/install/helm/install.go index bae89829f2..e41eae4910 100644 --- a/internal/cli/install/helm/install.go +++ b/internal/cli/install/helm/install.go @@ -45,13 +45,16 @@ func NewHelm(k8sCfg *rest.Config, forNamespace string) (*Helm, error) { // Install installs a given Helm chart. func (c *Helm) Install(ctx context.Context, status *printer.StatusPrinter, opts Config) (*release.Release, error) { histClient := action.NewHistory(c.helmCfg) - //histClient.Max = 1 rels, err := histClient.Run(opts.ReleaseName) var runFn Run switch { case err == nil: - if err := PrintReleaseStatus("Detected existing Botkube installation:", status, rels[len(rels)-1]); err != nil { - return nil, err + if len(rels) > 0 { // it shouldn't happen, because there is not found error in such cases, however it better to be on the safe side. + if err := PrintReleaseStatus("Detected existing Botkube installation:", status, rels[len(rels)-1]); err != nil { + return nil, err + } + } else { + status.Infof("Detected existing Botkube installation") } prompt := &survey.Confirm{ diff --git a/internal/cli/install/helm/status.go b/internal/cli/install/helm/status.go index ea7e44ead4..df07b9c118 100644 --- a/internal/cli/install/helm/status.go +++ b/internal/cli/install/helm/status.go @@ -30,14 +30,20 @@ func PrintReleaseStatus(header string, status *printer.StatusPrinter, r *release properties := make(map[string]string) properties["Name"] = r.Name - if !r.Info.LastDeployed.IsZero() { - properties["LastDeployed"] = r.Info.LastDeployed.Format(time.ANSIC) - } properties["Namespace"] = r.Namespace - properties["Status"] = r.Info.Status.String() - properties["Version"] = r.Chart.AppVersion() properties["Revision"] = fmt.Sprintf("%d", r.Version) - properties["Description"] = r.Info.Description + + if r.Info != nil { + if !r.Info.LastDeployed.IsZero() { + properties["LastDeployed"] = r.Info.LastDeployed.Format(time.ANSIC) + } + properties["Status"] = r.Info.Status.String() + properties["Description"] = r.Info.Description + } + + if r.Chart != nil { + properties["Version"] = r.Chart.AppVersion() + } desc, err := renderer.Render(properties, true) if err != nil { diff --git a/internal/cli/install/install.go b/internal/cli/install/install.go index 4e996e9e2e..d6ff5f1adc 100644 --- a/internal/cli/install/install.go +++ b/internal/cli/install/install.go @@ -22,6 +22,8 @@ import ( "github.com/kubeshop/botkube/internal/kubex" ) +const messageInitialBufferSize = 100 + // Install installs Botkube Helm chart into cluster. func Install(ctx context.Context, w io.Writer, k8sCfg *kubex.ConfigWithMeta, opts Config) (err error) { ctxWithTimeout, cancel := context.WithCancel(ctx) @@ -77,12 +79,12 @@ func Install(ctx context.Context, w io.Writer, k8sCfg *kubex.ConfigWithMeta, opt } parallel, _ := errgroup.WithContext(ctxWithTimeout) + podScheduledIndicator := make(chan string) - podWaitErrors := make(chan error, 1) - podWaitPhase := make(chan string, 10) + podWaitResult := make(chan error, 1) parallel.Go(func() error { - err := kubex.WaitForPod(ctxWithTimeout, clientset, opts.HelmParams.Namespace, opts.HelmParams.ReleaseName, kubex.PodReady(podScheduledIndicator, podWaitPhase, time.Now())) - podWaitErrors <- err + err := kubex.WaitForPod(ctxWithTimeout, clientset, opts.HelmParams.Namespace, opts.HelmParams.ReleaseName, kubex.PodReady(podScheduledIndicator, time.Now())) + podWaitResult <- err return nil }) @@ -109,7 +111,7 @@ func Install(ctx context.Context, w io.Writer, k8sCfg *kubex.ConfigWithMeta, opt return fmt.Errorf("Timed out waiting for Pod") } - messages := make(chan []byte, opts.LogsScrollingHeight) + messages := make(chan []byte, messageInitialBufferSize) streamLogCtx, cancelStreamLogs := context.WithCancel(context.Background()) defer cancelStreamLogs() parallel.Go(func() error { @@ -117,13 +119,12 @@ func Install(ctx context.Context, w io.Writer, k8sCfg *kubex.ConfigWithMeta, opt return logs.StartsLogsStreaming(streamLogCtx, clientset, opts.HelmParams.Namespace, podName, messages) }) - logsPrinter := logs.NewFixedHeightPrinter( - opts.LogsScrollingHeight, + logsPrinter := logs.NewPrinter( podName, ) parallel.Go(func() error { - logsPrinter.Start(ctxWithTimeout) + logsPrinter.Start(ctxWithTimeout, status) return nil }) parallel.Go(func() error { @@ -131,7 +132,7 @@ func Install(ctx context.Context, w io.Writer, k8sCfg *kubex.ConfigWithMeta, opt select { case <-ctxWithTimeout.Done(): // it's canceled on OS signals or if function passed to 'Go' method returns a non-nil error return ctxWithTimeout.Err() - case err := <-podWaitErrors: + case err := <-podWaitResult: time.Sleep(time.Second) cancelStreamLogs() return err @@ -144,8 +145,6 @@ func Install(ctx context.Context, w io.Writer, k8sCfg *kubex.ConfigWithMeta, opt select { case <-ctxWithTimeout.Done(): // it's canceled on OS signals or if function passed to 'Go' method returns a non-nil error return ctxWithTimeout.Err() - case ph := <-podWaitPhase: - logsPrinter.UpdatePodPhase(ph) case entry, ok := <-messages: if !ok { logsPrinter.Stop() @@ -158,7 +157,10 @@ func Install(ctx context.Context, w io.Writer, k8sCfg *kubex.ConfigWithMeta, opt err = parallel.Wait() if err != nil { - printFailedInstallMessage(opts.HelmParams.Version, opts.HelmParams.Namespace, podName, w) + printErr := printFailedInstallMessage(opts.HelmParams.Version, opts.HelmParams.Namespace, podName, w) + if printErr != nil { + return fmt.Errorf("%s: %v", printErr, err) + } return err } diff --git a/internal/cli/install/logs/json_parser.go b/internal/cli/install/logs/json_parser.go index 6e90fbaf6e..49bdcf481c 100644 --- a/internal/cli/install/logs/json_parser.go +++ b/internal/cli/install/logs/json_parser.go @@ -12,33 +12,19 @@ import ( "github.com/kubeshop/botkube/internal/cli" ) +// JSONParser knows how to parse JSON formatted logs. type JSONParser struct{} -func (p *JSONParser) ParseLine(line string) map[string]any { - var out map[string]any - err := json.Unmarshal([]byte(line), &out) - if err != nil { - return nil - } - return out -} - // ParseLineIntoCharm returns parsed log line with charm logger support. -func (k *JSONParser) ParseLineIntoCharm(line string) ([]any, charmlog.Level) { - result := k.ParseLine(line) +func (j *JSONParser) ParseLineIntoCharm(line string) ([]any, charmlog.Level) { + result := j.parseLine(line) if result == nil { return nil, 0 } var fields []any - //if k.ReportTimestamp { - // parseAny, _ := dateparse.ParseAny(result["time"]) - // fields = append(fields, charmlog.TimestampKey, parseAny) - //} - lvl := charmlog.ParseLevel(fmt.Sprint(result["level"])) - // todo, check and ignore debug fields = append(fields, charmlog.LevelKey, lvl) fields = append(fields, charmlog.MessageKey, result["msg"]) @@ -58,3 +44,12 @@ func (k *JSONParser) ParseLineIntoCharm(line string) ([]any, charmlog.Level) { return fields, lvl } + +func (*JSONParser) parseLine(line string) map[string]any { + var out map[string]any + err := json.Unmarshal([]byte(line), &out) + if err != nil { + return nil + } + return out +} diff --git a/internal/cli/install/logs/k8s.go b/internal/cli/install/logs/k8s.go index 354e102bfb..5f16fa023b 100644 --- a/internal/cli/install/logs/k8s.go +++ b/internal/cli/install/logs/k8s.go @@ -42,9 +42,6 @@ func StartsLogsStreaming(ctx context.Context, clientset *kubernetes.Clientset, n bytes, readErr := r.ReadBytes('\n') // write first, as there might be some chars already loaded out <- bytes - //if strings.Contains(string(bytes), "Botkube connected to") { - // return nil - //} switch readErr { case nil: case io.EOF: diff --git a/internal/cli/install/logs/printer.go b/internal/cli/install/logs/printer.go index 0cd22b5917..dc8d519476 100644 --- a/internal/cli/install/logs/printer.go +++ b/internal/cli/install/logs/printer.go @@ -1,152 +1,90 @@ package logs import ( - "bytes" "context" "fmt" "os" "strings" - "time" "github.com/charmbracelet/log" charmlog "github.com/charmbracelet/log" "github.com/morikuni/aec" - "github.com/muesli/termenv" + "github.com/muesli/reflow/indent" "github.com/kubeshop/botkube/internal/cli" "github.com/kubeshop/botkube/internal/cli/printer" ) -type FixedHeightPrinter struct { - height int - logsBuffer []string - podPhase string - podName string - newLog chan string - newPodPhase chan string - stop chan struct{} - parser JSONParser - logger *log.Logger +type Printer struct { + podName string + newLog chan string + stop chan struct{} + parser JSONParser + logger *log.Logger } -func NewFixedHeightPrinter(height int, name string) *FixedHeightPrinter { - return &FixedHeightPrinter{ - height: height, - logsBuffer: []string{}, - newLog: make(chan string, 10), - newPodPhase: make(chan string, 10), - stop: make(chan struct{}), +// NewPrinter creates a new Printer instance. +func NewPrinter(podName string) *Printer { + return &Printer{ + newLog: make(chan string, 10), + stop: make(chan struct{}), logger: log.NewWithOptions(os.Stdout, log.Options{ Formatter: log.TextFormatter, }), - podName: name, + podName: podName, parser: JSONParser{}, } } -func (f *FixedHeightPrinter) Start(ctx context.Context) { - refreshDuration := 100 * time.Millisecond - idleDelay := time.NewTimer(refreshDuration) - defer idleDelay.Stop() +// Start starts the log streaming process. +func (f *Printer) Start(ctx context.Context, status *printer.StatusPrinter) { + status.InfoWithBody("Streaming logs...", indent.String(fmt.Sprintf("Pod: %s", f.podName), 4)) + fmt.Println() - buff := bytes.Buffer{} - status := printer.NewStatus(&buff, "") - status.Step("Streaming logs...") - termenv.SaveCursorPosition() for { - f.printData(buff.String() + "\n") // it's without new line when it's in progress - idleDelay.Reset(refreshDuration) - select { case <-f.stop: - status.End(true) - termenv.RestoreCursorPosition() - f.printStatusHeader(buff.String()) - f.printLogs(true) - fmt.Println() return case <-ctx.Done(): - status.End(false) - termenv.RestoreCursorPosition() - - f.printStatusHeader(buff.String()) - f.printLogs(true) - fmt.Println() + status.Infof("Requested logs streaming cancel...") return - case <-idleDelay.C: case entry := <-f.newLog: - f.logsBuffer = append(f.logsBuffer, entry) - if len(f.logsBuffer) > f.height { - //now we need to simulate scrolling, so all lines are moved N-1, where the first line is just removed. - f.logsBuffer = f.logsBuffer[1:] - } - case podPhase := <-f.newPodPhase: - f.podPhase = podPhase + f.printLogs(entry) } - - fmt.Print(aec.Up(uint(f.height + 4))) } } -func (f *FixedHeightPrinter) printData(header string) { - f.printStatusHeader(header) - f.printLogs(false) -} -func (f *FixedHeightPrinter) printStatusHeader(step string) { - fmt.Println(step) - fmt.Printf(" Pods: %s Phase: %s\n", f.podName, f.podPhase) - fmt.Println() -} - -func (f *FixedHeightPrinter) UpdatePodPhase(phase string) { +// AppendLogEntry appends a log entry to the printer. +func (f *Printer) AppendLogEntry(entry string) { + if strings.TrimSpace(entry) == "" { + return + } select { - case f.newPodPhase <- phase: + case f.newLog <- entry: default: } } -func (f *FixedHeightPrinter) printLogs(skip bool) { - wroteLines := 0 - for _, item := range f.logsBuffer { - fields, lvl := f.parser.ParseLineIntoCharm(item) - if fields == nil { - wroteLines++ - f.printLogLine(item) - continue - } - if lvl == charmlog.DebugLevel && !cli.VerboseMode.IsEnabled() { - continue - } - wroteLines++ - fmt.Print(aec.EraseLine(aec.EraseModes.Tail)) - fmt.Print(aec.Column(6)) - f.logger.With(fields...).Print(nil) - } +// Stop stops the printer. +func (f *Printer) Stop() { + close(f.stop) +} - if skip { +func (f *Printer) printLogs(item string) { + fields, lvl := f.parser.ParseLineIntoCharm(item) + if fields == nil { + f.printLogLine(item) return } - for i := wroteLines; i < f.height; i++ { - f.printLogLine("\n") + if lvl == charmlog.DebugLevel && !cli.VerboseMode.IsEnabled() { + return } -} - -func (f *FixedHeightPrinter) printLogLine(line string) { fmt.Print(aec.EraseLine(aec.EraseModes.Tail)) fmt.Print(aec.Column(6)) - fmt.Print(line) -} - -func (f *FixedHeightPrinter) AppendLogEntry(entry string) { - if strings.TrimSpace(entry) == "" { - return - } - select { - case f.newLog <- entry: - default: - } + f.logger.With(fields...).Print(nil) } -func (f *FixedHeightPrinter) Stop() { - close(f.stop) +func (f *Printer) printLogLine(line string) { + fmt.Print(aec.Column(6)) + fmt.Print(line) } diff --git a/internal/cli/printer/status.go b/internal/cli/printer/status.go index 6b1ee30833..be4cb5970b 100644 --- a/internal/cli/printer/status.go +++ b/internal/cli/printer/status.go @@ -50,13 +50,13 @@ func NewStatus(w io.Writer, header string) *StatusPrinter { st := &StatusPrinter{ w: w, } - //if cli.IsSmartTerminal(w) { - st.durationSprintf = color.New(color.Faint, color.Italic).Sprintf - st.spinner = NewDynamicSpinner(w) - //} else { - // st.durationSprintf = fmt.Sprintf - // st.spinner = NewStaticSpinner(w) - //} + if cli.IsSmartTerminal(w) { + st.durationSprintf = color.New(color.Faint, color.Italic).Sprintf + st.spinner = NewDynamicSpinner(w) + } else { + st.durationSprintf = fmt.Sprintf + st.spinner = NewStaticSpinner(w) + } return st } diff --git a/internal/kubex/wait.go b/internal/kubex/wait.go index 03d99c8e16..926eb30ef2 100644 --- a/internal/kubex/wait.go +++ b/internal/kubex/wait.go @@ -38,7 +38,7 @@ var ( ) // PodReady returns true if the Pod is read. -func PodReady(podScheduledIndicator, phase chan string, since time.Time) func(event watch.Event) (bool, error) { +func PodReady(podScheduledIndicator chan string, since time.Time) func(event watch.Event) (bool, error) { informed := false sinceK8sTime := metav1.NewTime(since) return func(event watch.Event) (bool, error) { @@ -53,7 +53,6 @@ func PodReady(podScheduledIndicator, phase chan string, since time.Time) func(ev return false, nil } - phase <- string(pod.Status.Phase) if pod.Status.Phase == corev1.PodRunning && !informed { informed = true podScheduledIndicator <- pod.Name @@ -61,7 +60,7 @@ func PodReady(podScheduledIndicator, phase chan string, since time.Time) func(ev } for _, cond := range pod.Status.ContainerStatuses { - if cond.Ready == false && cond.RestartCount > 0 { + if !cond.Ready && cond.RestartCount > 0 { // pod was already restarted because of the problem, we restart botkube on permanent errors mostly, so let's stop watching return true, errPodRestartedWithError }