feat: improve finalizing step feedback (#498)

* feat: improve finalizing step feedback

provide users with more feedback during the finalizing step of the
installation. shows the images being pushed.

* chore: adjusting user feedback

* chore: fix 'make clean' and bumps kots version

* chore: fix messages for online installations

* chore: working on airgap messaging

* chore: working on airgap messaging

* chore: working on airgap messaging

* chore: working on airgap messaging

* chore: working on airgap messaging

* chore: working on airgap messaging

* chore: fixed tests

* chore: working on airgap messaging

* chore: working on airgap messaging

* chore: working on airgap messaging

Author: ricardomaraschini

Makefile

@@ -149,6 +149,7 @@ e2e-test:
 clean:
 	rm -rf output
 	rm -rf pkg/goods/bins
+	rm -rf pkg/goods/internal/bins
 
 .PHONY: lint
 lint:

pkg/addons/adminconsole/adminconsole.go

@@ -7,6 +7,8 @@ import (
 	"encoding/base64"
 	"fmt"
 	"os"
+	"regexp"
+	"strings"
 	"time"
 
 	"github.com/k0sproject/dig"
@@ -41,6 +43,7 @@ var (
 	Version                 = "v0.0.0"
 	ImageOverride           = ""
 	MigrationsImageOverride = ""
+	CounterRegex            = regexp.MustCompile(`(\d+)/(\d+)`)
 )
 
 // protectedFields are helm values that are not overwritten when upgrading the addon.
@@ -207,6 +210,99 @@ func (a *AdminConsole) GetAdditionalImages() []string {
 	return nil
 }
 
+// MaskKotsOutputForOnline masks the kots cli output during online installations. For
+// online installations we only want to print "Finalizing" until it is done and then
+// print "Finished!".
+func (a *AdminConsole) MaskKotsOutputForOnline() spinner.MaskFn {
+	return func(message string) string {
+		if strings.Contains(message, "Finished") {
+			return message
+		}
+		return "Finalizing"
+	}
+}
+
+// MaskKotsOutputForAirgap masks the kots cli output during airgap installations. This
+// function replaces some of the messages being printed to the user so the output looks
+// nicer.
+func (a *AdminConsole) MaskKotsOutputForAirgap() spinner.MaskFn {
+	current := "Uploading air gap bundle"
+	return func(message string) string {
+		switch {
+		case strings.Contains(message, "Pushing application images"):
+			current = message
+		case strings.Contains(message, "Pushing embedded cluster artifacts"):
+			current = message
+		case strings.Contains(message, "Waiting for Admin Console"):
+			current = "Finalizing"
+		case strings.Contains(message, "Finished!"):
+			current = message
+		}
+		return current
+	}
+}
+
+// KostsOutputLineBreaker creates a line break (new spinner) when some of the messages
+// are printed to the user. For example: after finishing all image uploads we want to
+// have a new spinner for the artifacts upload.
+func (a *AdminConsole) KostsOutputLineBreaker() spinner.LineBreakerFn {
+	// finished is an auxiliary function that evaluates if a message refers to a
+	// step that has been finished. We determine that by inspected if the message
+	// contains %d/%d and both integers are equal.
+	finished := func(message string) bool {
+		matches := CounterRegex.FindStringSubmatch(message)
+		if len(matches) != 3 {
+			return false
+		}
+		var counter int
+		if _, err := fmt.Sscanf(matches[1], "%d", &counter); err != nil {
+			return false
+		}
+		var total int
+		if _, err := fmt.Sscanf(matches[2], "%d", &total); err != nil {
+			return false
+		}
+		return counter == total
+	}
+
+	var previous string
+	var seen = map[string]bool{}
+	return func(current string) (bool, string) {
+		defer func() {
+			previous = current
+		}()
+
+		// if we have already seen this message we certainly have already assessed
+		// if a break line as necessary or not, on this case we return false so we
+		// do not keep breaking lines indefinitely.
+		if _, ok := seen[current]; ok {
+			return false, ""
+		}
+		seen[current] = true
+
+		// if the previous message evaluated does not relate to an end of a process
+		// we don't want to break the line. i.e. we only want to break the line when
+		// the previous evaluated message contains %d/%d and both integers are equal.
+		if !finished(previous) {
+			return false, ""
+		}
+
+		// if we are printing a message about pushing the embedded cluster artifacts
+		// it means that we have finished with the images and we want to break the line.
+		if strings.Contains(current, "Pushing embedded cluster artifacts") {
+			return true, "Application images are ready!"
+		}
+
+		// if we are printing a message about the finalization of the installation it
+		// means that the embedded cluster artifacts are ready and we want to break the
+		// line.
+		if current == "Finalizing" {
+			return true, "Embedded cluster artifacts are ready!"
+		}
+		return false, ""
+	}
+}
+
 // Outro waits for the adminconsole to be ready.
 func (a *AdminConsole) Outro(ctx context.Context, cli client.Client) error {
 	loading := spinner.Start()
@@ -244,28 +340,27 @@ func (a *AdminConsole) Outro(ctx context.Context, cli client.Client) error {
 		return fmt.Errorf("error waiting for admin console: %v", lasterr)
 	}
 
+	loading.Closef("Admin Console is ready!")
 	if a.licenseFile == "" {
-		loading.Closef("Admin Console is ready!")
 		return nil
 	}
 
-	loading.Infof("Finalizing")
-
 	kotsBinPath, err := goods.MaterializeInternalBinary("kubectl-kots")
 	if err != nil {
-		loading.Close()
 		return fmt.Errorf("unable to materialize kubectl-kots binary: %w", err)
 	}
 	defer os.Remove(kotsBinPath)
 
 	license, err := helpers.ParseLicense(a.licenseFile)
 	if err != nil {
+		loading.CloseWithError()
 		return fmt.Errorf("unable to parse license: %w", err)
 	}
 
 	var appVersionLabel string
 	var channelSlug string
 	if channelRelease, err := release.GetChannelRelease(); err != nil {
+		loading.CloseWithError()
 		return fmt.Errorf("unable to get channel release: %w", err)
 	} else if channelRelease != nil {
 		appVersionLabel = channelRelease.VersionLabel
@@ -277,6 +372,8 @@ func (a *AdminConsole) Outro(ctx context.Context, cli client.Client) error {
 		upstreamURI = fmt.Sprintf("%s/%s", upstreamURI, channelSlug)
 	}
 
+	var lbreakfn spinner.LineBreakerFn
+	maskfn := a.MaskKotsOutputForOnline()
 	installArgs := []string{
 		"install",
 		upstreamURI,
@@ -290,14 +387,17 @@ func (a *AdminConsole) Outro(ctx context.Context, cli client.Client) error {
 	}
 	if a.airgapBundle != "" {
 		installArgs = append(installArgs, "--airgap-bundle", a.airgapBundle)
+		maskfn = a.MaskKotsOutputForAirgap()
+		lbreakfn = a.KostsOutputLineBreaker()
 	}
 
-	if _, err := helpers.RunCommand(kotsBinPath, installArgs...); err != nil {
-		loading.Close()
+	loading = spinner.Start(spinner.WithMask(maskfn), spinner.WithLineBreaker(lbreakfn))
+	if err := helpers.RunCommandWithWriter(loading, kotsBinPath, installArgs...); err != nil {
+		loading.CloseWithError()
 		return fmt.Errorf("unable to install the application: %w", err)
 	}
 
-	loading.Closef("Admin Console is ready!")
+	loading.Closef("Finished!")
 	a.printSuccessMessage(license.Spec.AppSlug)
 	return nil
 }

pkg/helpers/command.go

@@ -3,29 +3,40 @@ package helpers
 import (
 	"bytes"
 	"fmt"
+	"io"
 	"os/exec"
 
 	"github.com/sirupsen/logrus"
 )
 
-// RunCommand spawns a command and capture its output. Outputs are logged using the
-// logrus package and stdout is returned as a string.
-func RunCommand(bin string, args ...string) (string, error) {
+// RunCommandWithWriter runs a the provided command. The stdout of the command is
+// written to the provider writer.
+func RunCommandWithWriter(to io.Writer, bin string, args ...string) error {
 	fullcmd := append([]string{bin}, args...)
 	logrus.Debugf("running command: %v", fullcmd)
 
-	stdout := bytes.NewBuffer(nil)
 	stderr := bytes.NewBuffer(nil)
+	stdout := bytes.NewBuffer(nil)
 	cmd := exec.Command(bin, args...)
-	cmd.Stdout = stdout
+	cmd.Stdout = io.MultiWriter(to, stdout)
 	cmd.Stderr = stderr
 	if err := cmd.Run(); err != nil {
 		logrus.Debugf("failed to run command:")
 		logrus.Debugf("stdout: %s", stdout.String())
 		logrus.Debugf("stderr: %s", stderr.String())
 		if stderr.String() != "" {
-			return "", fmt.Errorf("%w: %s", err, stderr.String())
+			return fmt.Errorf("%w: %s", err, stderr.String())
 		}
+		return err
+	}
+	return nil
+}
+
+// RunCommand spawns a command and capture its output. Outputs are logged using the
+// logrus package and stdout is returned as a string.
+func RunCommand(bin string, args ...string) (string, error) {
+	stdout := bytes.NewBuffer(nil)
+	if err := RunCommandWithWriter(stdout, bin, args...); err != nil {
 		return "", err
 	}
 	return stdout.String(), nil

pkg/spinner/spinner.go

@@ -13,9 +13,9 @@ var blocks = []string{"◐", "◓", "◑", "◒"}
 type WriteFn func(string, ...any) (int, error)
 
 // LineBreakerFn is a function that determines if it is time to break the
-// line thus creating a new spinner line. The previous step is flagged as
-// success.
-type LineBreakerFn func(string) bool
+// line thus creating a new spinner line. Returns a boolean and a string
+// indicating what needs to be printed before the line break.
+type LineBreakerFn func(string) (bool, string)
 
 // MaskFn is a function that masks a message. Receives a string and
 // returns a string, the returned string is printed to the terminal.
@@ -109,20 +109,22 @@ func (m *MessageWriter) loop() {
 			counter++
 		}
 
-		var lbreak bool
-		if m.lbreak != nil && previous != message {
-			lbreak = m.lbreak(message)
-		}
-
 		if m.mask != nil {
 			message = m.mask(message)
 		}
 
+		if m.lbreak != nil && previous != message {
+			if lbreak, lcontent := m.lbreak(message); lbreak {
+				if diff := len(previous) - len(lcontent); diff > 0 {
+					suffix := strings.Repeat(" ", diff)
+					lcontent = fmt.Sprintf("%s%s", lcontent, suffix)
+				}
+				m.printf("\033[K\r✔  %s\n", lcontent)
+			}
+		}
+
 		pos := counter % len(blocks)
 		if !end {
-			if lbreak {
-				m.printf("\033[K\r✔  %s\n", previous)
-			}
 			m.printf("\033[K\r%s  %s", blocks[pos], message)
 			continue
 		}

pkg/spinner/spinner_test.go

@@ -111,8 +111,14 @@ func TestMask(t *testing.T) {
 
 func TestLineBreak(t *testing.T) {
 	buf := bytes.NewBuffer(nil)
-	lbreak := func(s string) bool {
-		return s == "test 3" || s == "test 8"
+	lbreak := func(s string) (bool, string) {
+		if s == "test 3" {
+			return true, "ping 2"
+		}
+		if s == "test 8" {
+			return true, "ping 7"
+		}
+		return false, ""
 	}
 	pb := Start(
 		WithWriter(WriteTo(buf)),
@@ -123,11 +129,11 @@ func TestLineBreak(t *testing.T) {
 	}
 	pb.Close()
 	// we expect the following output:
-	// ✔  test 2 (\n)
-	// ✔  test 7 (\n)
+	// ✔  ping 2 (\n)
+	// ✔  ping 7 (\n)
 	// ✔  test 99 (\n)
 	assert.Equal(t, strings.Count(buf.String(), "\n"), 3)
-	assert.Contains(t, buf.String(), "test 2")
-	assert.Contains(t, buf.String(), "test 7")
+	assert.Contains(t, buf.String(), "ping 2")
+	assert.Contains(t, buf.String(), "ping 7")
 	assert.Contains(t, buf.String(), "test 99")
 }