improved commands output: add --time format option and color output

Signed-off-by: Adphi <philippe.adrien.nousse@gmail.com>

cmd/d2vm/build.go

@@ -31,7 +31,7 @@ import (
 
 var (
 	file           = "Dockerfile"
-	tag            = uuid.New().String()
+	tag            = "d2vm-"+uuid.New().String()
 	networkManager string
 	buildArgs      []string
 	buildCmd       = &cobra.Command{

cmd/d2vm/main.go

@@ -15,11 +15,15 @@
 package main
 
 import (
+	"bytes"
 	"context"
 	"fmt"
 	"os"
 	"os/signal"
+	"strings"
+	"time"
 
+	"github.com/fatih/color"
 	"github.com/sirupsen/logrus"
 	"github.com/spf13/cobra"
 
@@ -28,18 +32,26 @@ import (
 )
 
 var (
-	output   = "disk0.qcow2"
+	output     = "disk0.qcow2"
-	size     = "1G"
+	size       = "1G"
-	password = "root"
+	password   = "root"
-	force    = false
+	force      = false
-	verbose  = false
+	verbose    = false
-	format   = "qcow2"
+	timeFormat = ""
+	format     = "qcow2"
 
 	rootCmd = &cobra.Command{
 		Use:          "d2vm",
 		SilenceUsage: true,
 		Version:      d2vm.Version,
 		PersistentPreRun: func(cmd *cobra.Command, args []string) {
+			switch timeFormat {
+			case "full", "f":
+			case "relative", "rel", "r":
+			case "none", "":
+			default:
+				logrus.Fatalf("invalid time format: %s. Valid format: 'relative', 'full'", timeFormat)
+			}
 			if verbose {
 				logrus.SetLevel(logrus.TraceLevel)
 			}
@@ -66,4 +78,53 @@ func init() {
 	rootCmd.PersistentFlags().BoolVarP(&verbose, "debug", "d", false, "Enable Debug output")
 	rootCmd.PersistentFlags().MarkDeprecated("debug", "use -v instead")
 	rootCmd.PersistentFlags().BoolVarP(&verbose, "verbose", "v", false, "Enable Verbose output")
+	rootCmd.PersistentFlags().StringVarP(&timeFormat, "time", "t", "none", "Enable formated timed output, valide formats: 'relative (rel | r)', 'full (f)'")
+	color.NoColor = false
+	logrus.StandardLogger().Formatter = &logfmtFormatter{start: time.Now()}
+}
+
+const (
+	red    = 31
+	yellow = 33
+	blue   = 36
+	gray   = 90
+)
+
+type logfmtFormatter struct {
+	start time.Time
+}
+
+func (f *logfmtFormatter) Format(entry *logrus.Entry) ([]byte, error) {
+	var b bytes.Buffer
+	var c *color.Color
+	switch entry.Level {
+	case logrus.DebugLevel, logrus.TraceLevel:
+		c = color.New(gray)
+	// case logrus.InfoLevel:
+	//	c = color.New(blue)
+	case logrus.WarnLevel:
+		c = color.New(yellow)
+	case logrus.ErrorLevel, logrus.FatalLevel, logrus.PanicLevel:
+		c = color.New(red)
+	default:
+		c = color.New(color.FgWhite)
+	}
+	msg := entry.Message
+	if len(entry.Message) > 0 && entry.Level < logrus.DebugLevel {
+		msg = strings.ToTitle(string(msg[0])) + msg[1:]
+	}
+
+	var err error
+	switch timeFormat {
+	case "full", "f":
+		_, err = c.Fprintf(&b, "[%s] %s\n", entry.Time.Format("2006-01-02 15:04:05"), entry.Message)
+	case "relative", "rel", "r":
+		_, err = c.Fprintf(&b, "[%5v] %s\n", entry.Time.Sub(f.start).Truncate(time.Second).String(), msg)
+	default:
+		_, err = c.Fprintln(&b, msg)
+	}
+	if err != nil {
+		return nil, err
+	}
+	return b.Bytes(), nil
 }

cmd/d2vm/run/hetzner.go

@@ -24,6 +24,7 @@ import (
 	"os/exec"
 	"path/filepath"
 	"runtime"
+	"strings"
 	"time"
 
 	"github.com/dustin/go-humanize"
@@ -62,7 +63,7 @@ var (
 )
 
 func init() {
-	HetznerCmd.Flags().StringVarP(&hetznerToken, "token", "t", "", "Hetzner Cloud API token [$"+hetznerTokenEnv+"]")
+	HetznerCmd.Flags().StringVar(&hetznerToken, "token", "", "Hetzner Cloud API token [$"+hetznerTokenEnv+"]")
 	HetznerCmd.Flags().StringVarP(&hetznerSSHUser, "user", "u", "root", "d2vm image ssh user")
 	HetznerCmd.Flags().StringVarP(&hetznerSSHKeyPath, "ssh-key", "i", "", "d2vm image identity key")
 	HetznerCmd.Flags().BoolVar(&hetznerRemove, "rm", false, "remove server when done")
@@ -175,6 +176,7 @@ func runHetzner(ctx context.Context, imgPath string, stdin io.Reader, stderr io.
 		return err
 	}
 	f, err := sftpc.Create(sparsecatPath)
+	logrus.Debugf("creating sparsecat on remote host")
 	if err != nil {
 		return err
 	}
@@ -197,7 +199,9 @@ func runHetzner(ctx context.Context, imgPath string, stdin io.Reader, stderr io.
 			}
 			defer s.Close()
 			logrus.Infof("installing cloud-guest-utils on rescue server")
-			if b, err := s.CombinedOutput("apt update && apt install -y cloud-guest-utils"); err != nil {
+			cmd := "apt update && apt install -y cloud-guest-utils"
+			logrus.Debugf("$ %s", cmd)
+			if b, err := s.CombinedOutput(cmd); err != nil {
 				return fmt.Errorf("%v: %s", err, string(b))
 			}
 			return nil
@@ -245,8 +249,11 @@ func runHetzner(ctx context.Context, imgPath string, stdin io.Reader, stderr io.
 			} else {
 				cmd = fmt.Sprintf("dd of=%s", vmBlockPath)
 			}
+			logrus.Debugf("$ %s", cmd)
 			if b, err := wses.CombinedOutput(cmd); err != nil {
 				return fmt.Errorf("%v: %s", err, string(b))
+			} else {
+				logrus.Debugf(string(b))
 			}
 			return nil
 		}()
@@ -267,8 +274,12 @@ func runHetzner(ctx context.Context, imgPath string, stdin io.Reader, stderr io.
 	}
 	defer gses.Close()
 	logrus.Infof("resizing disk partition")
-	if b, err := gses.CombinedOutput(fmt.Sprintf("growpart %s 1", vmBlockPath)); err != nil {
+	cmd := fmt.Sprintf("growpart %s 1", vmBlockPath)
+	logrus.Debugf("$ %s", cmd)
+	if b, err := gses.CombinedOutput(cmd); err != nil {
 		return fmt.Errorf("%v: %s", err, string(b))
+	} else {
+		logrus.Debugf(string(b))
 	}
 	eses, err := sc.NewSession()
 	if err != nil {
@@ -276,7 +287,9 @@ func runHetzner(ctx context.Context, imgPath string, stdin io.Reader, stderr io.
 	}
 	defer eses.Close()
 	logrus.Infof("extending partition file system")
-	if b, err := eses.CombinedOutput(fmt.Sprintf("resize2fs %s1", vmBlockPath)); err != nil {
+	cmd = fmt.Sprintf("resize2fs %s1", vmBlockPath)
+	logrus.Debugf("$ %s", cmd)
+	if b, err := eses.CombinedOutput(cmd); err != nil {
 		return fmt.Errorf("%v: %s", err, string(b))
 	}
 	logrus.Infof("rebooting server")
@@ -314,11 +327,12 @@ wait:
 		args = append(args, "-i", hetznerSSHKeyPath)
 	}
 	args = append(args, fmt.Sprintf("%s@%s", hetznerSSHUser, sres.Server.PublicNet.IPv4.IP.String()))
-	cmd := exec.CommandContext(ctx, "ssh", args...)
+	logrus.Debugf("$ ssh %s", strings.Join(args, " "))
-	cmd.Stdin = stdin
+	sshCmd := exec.CommandContext(ctx, "ssh", args...)
-	cmd.Stderr = stderr
+	sshCmd.Stdin = stdin
-	cmd.Stdout = stdout
+	sshCmd.Stderr = stderr
-	if err := cmd.Run(); err != nil {
+	sshCmd.Stdout = stdout
+	if err := sshCmd.Run(); err != nil {
 		return err
 	}
 	return nil

convert.go

@@ -50,7 +50,7 @@ func Convert(ctx context.Context, img string, opts ...ConvertOption) error {
 		if err != nil {
 			return err
 		}
-		logrus.Infof("docker image based on %s", d.Release.Name)
+		logrus.Infof("docker image based on %s %s", d.Release.Name, d.Release.Version)
 		p := filepath.Join(tmpPath, docker.FormatImgName(img))
 		dir := filepath.Dir(p)
 		f, err := os.Create(p)

go.mod

@@ -33,12 +33,15 @@ require (
 	github.com/docker/docker-credential-helpers v0.6.4 // indirect
 	github.com/docker/go-connections v0.4.1-0.20190612165340-fd1b1942c4d5 // indirect
 	github.com/docker/go-units v0.4.0 // indirect
+	github.com/fatih/color v1.13.0 // indirect
 	github.com/gogo/protobuf v1.3.2 // indirect
 	github.com/golang/protobuf v1.5.2 // indirect
 	github.com/google/go-cmp v0.5.6 // indirect
 	github.com/inconshreveable/mousetrap v1.0.0 // indirect
 	github.com/klauspost/compress v1.13.6 // indirect
 	github.com/kr/fs v0.1.0 // indirect
+	github.com/mattn/go-colorable v0.1.12 // indirect
+	github.com/mattn/go-isatty v0.0.14 // indirect
 	github.com/matttproud/golang_protobuf_extensions v1.0.2-0.20181231171920-c182affec369 // indirect
 	github.com/mitchellh/go-homedir v1.1.0 // indirect
 	github.com/opencontainers/go-digest v1.0.0 // indirect

go.sum

@@ -319,6 +319,7 @@ github.com/envoyproxy/protoc-gen-validate v0.6.2/go.mod h1:2t7qjJNvHPx8IjnBOzl9E
 github.com/evanphx/json-patch v4.9.0+incompatible/go.mod h1:50XU6AFN0ol/bzJsmQLiYLvXMP4fmwYFNcr97nuDLSk=
 github.com/fatih/color v1.7.0/go.mod h1:Zm6kSWBoL9eyXnKyktHP6abPY2pDugNf5KwzbycvMj4=
 github.com/fatih/color v1.9.0/go.mod h1:eQcE1qtQxscV5RaZvpXrrb8Drkc3/DdQ+uUYCNjL+zU=
+github.com/fatih/color v1.13.0 h1:8LOYc1KYPPmyKMuN8QV2DNRWNbLo6LZ0iLs8+mlH53w=
 github.com/fatih/color v1.13.0/go.mod h1:kLAiJbzzSOZDVNGyDpeOxJ47H46qBXwg5ILebYFFOfk=
 github.com/form3tech-oss/jwt-go v3.2.2+incompatible/go.mod h1:pbq4aXjuKjdthFRnoDwaVPLA+WlJuPGy+QneDUgJi2k=
 github.com/frankban/quicktest v1.11.3/go.mod h1:wRf/ReqHper53s+kmmSZizM8NamnL3IM0I9ntUbOk+k=
@@ -559,6 +560,7 @@ github.com/mattn/go-colorable v0.0.9/go.mod h1:9vuHe8Xs5qXnSaW/c/ABM9alt+Vo+STaO
 github.com/mattn/go-colorable v0.1.4/go.mod h1:U0ppj6V5qS13XJ6of8GYAs25YV2eR4EVcfRqFIhoBtE=
 github.com/mattn/go-colorable v0.1.6/go.mod h1:u6P/XSegPjTcexA+o6vUJrdnUu04hMope9wVRipJSqc=
 github.com/mattn/go-colorable v0.1.9/go.mod h1:u6P/XSegPjTcexA+o6vUJrdnUu04hMope9wVRipJSqc=
+github.com/mattn/go-colorable v0.1.12 h1:jF+Du6AlPIjs2BiUiQlKOX0rt3SujHxPnksPKZbaA40=
 github.com/mattn/go-colorable v0.1.12/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4=
 github.com/mattn/go-isatty v0.0.3/go.mod h1:M+lRXTBqGeGNdLjl/ufCoiOlB5xdOkqRJdNxMWT7Zi4=
 github.com/mattn/go-isatty v0.0.4/go.mod h1:M+lRXTBqGeGNdLjl/ufCoiOlB5xdOkqRJdNxMWT7Zi4=
@@ -566,6 +568,7 @@ github.com/mattn/go-isatty v0.0.8/go.mod h1:Iq45c/XA43vh69/j3iqttzPXn0bhXyGjM0Hd
 github.com/mattn/go-isatty v0.0.10/go.mod h1:qgIWMr58cqv1PHHyhnkY9lrL7etaEgOFcMEpPG5Rm84=
 github.com/mattn/go-isatty v0.0.11/go.mod h1:PhnuNfih5lzO57/f3n+odYbM4JtupLOxQOAqxQCu2WE=
 github.com/mattn/go-isatty v0.0.12/go.mod h1:cbi8OIDigv2wuxKPP5vlRcQ1OAZbq2CE4Kysco4FUpU=
+github.com/mattn/go-isatty v0.0.14 h1:yVuAays6BHfxijgZPzw+3Zlu5yQgKGP2/hcQbHb7S9Y=
 github.com/mattn/go-isatty v0.0.14/go.mod h1:7GGIvUiUoEMVVmxf/4nioHXj79iQHKdU27kJ6hsGG94=
 github.com/mattn/go-runewidth v0.0.2/go.mod h1:LwmH8dsx7+W8Uxz3IHJYH5QSwggIsqBzpuz5H//U1FU=
 github.com/mattn/go-shellwords v1.0.3/go.mod h1:3xCvwCdWdlDJUrvuMn7Wuy9eWs4pE8vqg+NOMyg4B2o=

pkg/exec/exec.go

@@ -18,9 +18,10 @@ import (
 	"bytes"
 	"context"
 	"fmt"
-	"os"
 	"os/exec"
 	"strings"
+
+	"github.com/sirupsen/logrus"
 )
 
 var (
@@ -31,17 +32,18 @@ var (
 
 func SetDebug(debug bool) {
 	if debug {
-		Run = RunStdout
+		Run = RunDebug
+		logrus.SetLevel(logrus.DebugLevel)
 	} else {
 		Run = RunNoOut
 	}
 }
 
-func RunStdout(ctx context.Context, c string, args ...string) error {
+func RunDebug(ctx context.Context, c string, args ...string) error {
-	fmt.Printf("\n$ %s %s\n", c, strings.Join(args, " "))
+	logrus.Debugf("$ %s %s", c, strings.Join(args, " "))
 	cmd := exec.CommandContext(ctx, c, args...)
-	cmd.Stdout = os.Stdout
+	cmd.Stdout = logrus.StandardLogger().WriterLevel(logrus.DebugLevel)
-	cmd.Stderr = os.Stderr
+	cmd.Stderr = logrus.StandardLogger().WriterLevel(logrus.DebugLevel)
 	return cmd.Run()
 }