Add status tracking with loading spinners, clean up logging

This commit is contained in:
Benjamin Elder
2018-10-19 18:19:57 -07:00
parent 6ec36f3f2e
commit 33696bd22f
5 changed files with 258 additions and 21 deletions

View File

@@ -31,6 +31,9 @@ func NewCommand() *cobra.Command {
Use: "build",
Short: "Build one of [base-image, node-image]",
Long: "Build one of [base-image, node-image]",
RunE: func(cmd *cobra.Command, args []string) error {
return cmd.Help()
},
}
// add subcommands
cmd.AddCommand(baseimage.NewCommand())

View File

@@ -20,21 +20,39 @@ package kind
import (
"os"
"github.com/sirupsen/logrus"
log "github.com/sirupsen/logrus"
"github.com/spf13/cobra"
"sigs.k8s.io/kind/cmd/kind/build"
"sigs.k8s.io/kind/cmd/kind/create"
"sigs.k8s.io/kind/cmd/kind/delete"
logutil "sigs.k8s.io/kind/pkg/log"
)
const defaultLevel = logrus.WarnLevel
// Flags for the kind command
type Flags struct {
LogLevel string
}
// NewCommand returns a new cobra.Command implementing the root command for kind
func NewCommand() *cobra.Command {
flags := &Flags{}
cmd := &cobra.Command{
Use: "kind",
Short: "kind is a tool for managing local Kubernetes clusters",
Long: "kind creates and manages local Kubernetes clusters using Docker container 'nodes'",
PersistentPreRunE: func(cmd *cobra.Command, args []string) error {
return runE(flags, cmd, args)
},
RunE: func(cmd *cobra.Command, args []string) error {
return cmd.Help()
},
}
cmd.PersistentFlags().StringVar(&flags.LogLevel, "loglevel", defaultLevel.String(), "logrus log level")
// add all top level subcommands
cmd.AddCommand(build.NewCommand())
cmd.AddCommand(create.NewCommand())
@@ -42,6 +60,18 @@ func NewCommand() *cobra.Command {
return cmd
}
func runE(flags *Flags, cmd *cobra.Command, args []string) error {
level := defaultLevel
parsed, err := log.ParseLevel(flags.LogLevel)
if err != nil {
log.Warnf("Invalid log level '%s', defaulting to '%s'", flags.LogLevel, level)
} else {
level = parsed
}
log.SetLevel(level)
return nil
}
// Run runs the `kind` root command
func Run() error {
return NewCommand().Execute()
@@ -49,11 +79,17 @@ func Run() error {
// Main wraps Run, adding a log.Fatal(err) on error, and setting the log formatter
func Main() {
// let's explicitly set stdout
log.SetOutput(os.Stdout)
// this formatter is the default, but the timestamps output aren't
// particularly useful, they're relative to the command start
log.SetFormatter(&log.TextFormatter{
FullTimestamp: true,
TimestampFormat: "0102-15:04:05",
TimestampFormat: "15:04:05",
// we force colors because this only forces over the isTerminal check
// and this will not be accurately checkable later on when we wrap
// the logger output with our logutil.StatusFriendlyWriter
ForceColors: logutil.IsTerminal(log.StandardLogger().Out),
})
if err := Run(); err != nil {
os.Stderr.WriteString(err.Error())

View File

@@ -33,6 +33,7 @@ import (
"sigs.k8s.io/kind/pkg/cluster/config"
"sigs.k8s.io/kind/pkg/cluster/kubeadm"
"sigs.k8s.io/kind/pkg/exec"
logutil "sigs.k8s.io/kind/pkg/log"
)
// ClusterLabelKey is applied to each "node" docker container for identification
@@ -40,7 +41,8 @@ const ClusterLabelKey = "io.k8s.sigs.kind.cluster"
// Context is used to create / manipulate kubernetes-in-docker clusters
type Context struct {
name string
name string
status *logutil.Status
}
// similar to valid docker container names, but since we will prefix
@@ -103,6 +105,13 @@ func (c *Context) Create(cfg *config.Config) error {
return err
}
fmt.Printf("Creating cluster '%s' ...\n", c.ClusterName())
c.status = logutil.NewStatus()
c.status.MaybeWrapLogrus(log.StandardLogger())
defer c.status.End(false)
c.status.Start(fmt.Sprintf("Ensuring node image (%s) 🖼", cfg.Image))
// attempt to explicitly pull the image if it doesn't exist locally
// we don't care if this errors, we'll still try to run which also pulls
_, _ = docker.PullIfNotPresent(cfg.Image, 4)
@@ -118,16 +127,15 @@ func (c *Context) Create(cfg *config.Config) error {
if kubeadmConfig != "" {
defer os.Remove(kubeadmConfig)
}
if err != nil {
return err
}
log.Infof(
"You can now use the cluster with:\n\nexport KUBECONFIG=\"%s\"\nkubectl cluster-info",
c.status.End(true)
fmt.Printf(
"Cluster creation complete. You can now use the cluster with:\n\nexport KUBECONFIG=\"%s\"\nkubectl cluster-info\n",
c.KubeConfigPath(),
)
return nil
}
@@ -146,12 +154,14 @@ func (c *Context) provisionControlPlane(
nodeName string,
cfg *config.Config,
) (kubeadmConfigPath string, err error) {
c.status.Start(fmt.Sprintf("[%s] Creating node container 📦", nodeName))
// create the "node" container (docker run, but it is paused, see createNode)
node, err := createNode(nodeName, cfg.Image, c.ClusterLabel())
if err != nil {
return "", err
}
c.status.Start(fmt.Sprintf("[%s] Fixing mounts 🗻", nodeName))
// we need to change a few mounts once we have the container
// we'd do this ahead of time if we could, but --privileged implies things
// that don't seem to be configurable, and we need that flag
@@ -171,6 +181,7 @@ func (c *Context) provisionControlPlane(
}
}
c.status.Start(fmt.Sprintf("[%s] Starting systemd 🖥", nodeName))
// signal the node entrypoint to continue booting into systemd
if err := node.SignalStart(); err != nil {
// TODO(bentheelder): logging here
@@ -179,6 +190,7 @@ func (c *Context) provisionControlPlane(
return "", err
}
c.status.Start(fmt.Sprintf("[%s] Waiting for docker to be ready 🐋", nodeName))
// wait for docker to be ready
if !node.WaitForDocker(time.Now().Add(time.Second * 30)) {
// TODO(bentheelder): logging here
@@ -226,7 +238,12 @@ func (c *Context) provisionControlPlane(
}
// run kubeadm
if err := node.Run(
c.status.Start(
fmt.Sprintf(
"[%s] Starting Kubernetes (this may take a minute) ☸",
nodeName,
))
if err := node.RunQ(
// init because this is the control plane node
"kubeadm", "init",
// preflight errors are expected, in particular for swap being enabled
@@ -240,7 +257,7 @@ func (c *Context) provisionControlPlane(
return kubeadmConfig, errors.Wrap(err, "failed to init node with kubeadm")
}
// run any pre-kubeadm hooks
// run any post-kubeadm hooks
if cfg.NodeLifecycle != nil {
for _, hook := range cfg.NodeLifecycle.PostKubeadm {
if err := node.RunHook(&hook, "postKubeadm"); err != nil {
@@ -258,7 +275,7 @@ func (c *Context) provisionControlPlane(
}
// TODO(bentheelder): support other overlay networks
if err = node.Run(
if err = node.RunQ(
"/bin/sh", "-c",
`kubectl apply --kubeconfig=/etc/kubernetes/admin.conf -f "https://cloud.weave.works/k8s/net?k8s-version=$(kubectl version --kubeconfig=/etc/kubernetes/admin.conf | base64 | tr -d '\n')"`,
); err != nil {
@@ -268,7 +285,7 @@ func (c *Context) provisionControlPlane(
// if we are only provisioning one node, remove the master taint
// https://kubernetes.io/docs/setup/independent/create-cluster-kubeadm/#master-isolation
if cfg.NumNodes == 1 {
if err = node.Run(
if err = node.RunQ(
"kubectl", "--kubeconfig=/etc/kubernetes/admin.conf",
"taint", "nodes", "--all", "node-role.kubernetes.io/master-",
); err != nil {
@@ -277,7 +294,7 @@ func (c *Context) provisionControlPlane(
}
// add the default storage class
if err := node.RunWithInput(
if err := node.RunQWithInput(
strings.NewReader(defaultStorageClassManifest),
"kubectl", "--kubeconfig=/etc/kubernetes/admin.conf", "apply", "-f", "-",
); err != nil {

View File

@@ -96,8 +96,6 @@ func (nh *nodeHandle) SignalStart() error {
"-s", "SIGUSR1",
nh.nameOrID,
)
// TODO(bentheelder): collect output instead of connecting these
cmd.InheritOutput = true
return cmd.Run()
}
@@ -117,6 +115,21 @@ func (nh *nodeHandle) Run(command string, args ...string) error {
return cmd.Run()
}
// RunQ execs command, args... on the node without inherting stdout
func (nh *nodeHandle) RunQ(command string, args ...string) error {
cmd := exec.Command("docker", "exec")
cmd.Args = append(cmd.Args,
"-t", // use a tty so we can get output
"--privileged", // run with priliges so we can remount etc..
nh.nameOrID, // ... against the "node" container
command, // with the command specified
)
cmd.Args = append(cmd.Args,
args..., // finally, with the args specified
)
return cmd.Run()
}
// RunWithInput execs command, args... on the node, hooking input to stdin
func (nh *nodeHandle) RunWithInput(input io.Reader, command string, args ...string) error {
cmd := exec.Command("docker", "exec")
@@ -134,6 +147,22 @@ func (nh *nodeHandle) RunWithInput(input io.Reader, command string, args ...stri
return cmd.Run()
}
// RunQWithInput execs command, args... on the node, hooking input to stdin
func (nh *nodeHandle) RunQWithInput(input io.Reader, command string, args ...string) error {
cmd := exec.Command("docker", "exec")
cmd.Args = append(cmd.Args,
"-i", // interactive so we can supply input
"--privileged", // run with priliges so we can remount etc..
nh.nameOrID, // ... against the "node" container
command, // with the command specified
)
cmd.Args = append(cmd.Args,
args..., // finally, with the args specified
)
cmd.Stdin = input
return cmd.Run()
}
// RunHook runs a LifecycleHook on the node
// It will only return an error if hook.MustSucceed is true
func (nh *nodeHandle) RunHook(hook *config.LifecycleHook, phase string) error {
@@ -209,7 +238,7 @@ func tryUntil(until time.Time, try func() bool) bool {
// LoadImages loads image tarballs stored on the node into docker on the node
func (nh *nodeHandle) LoadImages() {
// load images cached on the node into docker
if err := nh.Run(
if err := nh.RunQ(
"find",
"/kind/images",
"-name", "*.tar",
@@ -221,14 +250,12 @@ func (nh *nodeHandle) LoadImages() {
// retag images that are missing -amd64 as image:tag -> image-amd64:tag
// bazel built images are currently missing these
// TODO(bentheelder): this is a bit gross, move this logic out of bash
if err := nh.Run(
if err := nh.RunQ(
"/bin/bash", "-c",
`docker images --format='{{.Repository}}:{{.Tag}}' | grep -v amd64 | xargs -L 1 -I '{}' /bin/bash -c 'docker tag "{}" "$(echo "{}" | sed s/:/-amd64:/)"'`,
); err != nil {
log.Warningf("Failed to re-tag docker images: %v", err)
}
nh.Run("docker", "images")
}
// FixMounts will correct mounts in the node container to meet the right
@@ -238,17 +265,17 @@ func (nh *nodeHandle) FixMounts() error {
// https://www.freedesktop.org/wiki/Software/systemd/ContainerInterface/
// however, we need other things from `docker run --privileged` ...
// and this flag also happens to make /sys rw, amongst other things
if err := nh.Run("mount", "-o", "remount,ro", "/sys"); err != nil {
if err := nh.RunQ("mount", "-o", "remount,ro", "/sys"); err != nil {
return err
}
// kubernetes needs shared mount propagation
if err := nh.Run("mount", "--make-shared", "/"); err != nil {
if err := nh.RunQ("mount", "--make-shared", "/"); err != nil {
return err
}
if err := nh.Run("mount", "--make-shared", "/run"); err != nil {
if err := nh.RunQ("mount", "--make-shared", "/run"); err != nil {
return err
}
if err := nh.Run("mount", "--make-shared", "/var/lib/docker"); err != nil {
if err := nh.RunQ("mount", "--make-shared", "/var/lib/docker"); err != nil {
return err
}
return nil

154
pkg/log/status.go Normal file
View File

@@ -0,0 +1,154 @@
/*
Copyright 2018 The Kubernetes Authors.
Licensed under the Apache License, Version 2.0 (the "License");
you may not use this file except in compliance with the License.
You may obtain a copy of the License at
http://www.apache.org/licenses/LICENSE-2.0
Unless required by applicable law or agreed to in writing, software
distributed under the License is distributed on an "AS IS" BASIS,
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
See the License for the specific language governing permissions and
limitations under the License.
*/
// Package log contains logging related functionality
package log
import (
"fmt"
"io"
"os"
"time"
"github.com/briandowns/spinner"
"github.com/sirupsen/logrus"
"golang.org/x/crypto/ssh/terminal"
)
// Status is used to track ongoing status in a CLI, with a nice loading spinner
// when attached to a terminal
type Status struct {
spinner *spinner.Spinner
status string
}
// NewStatus creates a new default Status
func NewStatus() *Status {
spin := spinner.New(
spinnerFrames,
100*time.Millisecond,
)
spin.Writer = os.Stdout
s := &Status{
spinner: spin,
}
return s
}
// StatusFriendlyWriter is used to wrap another Writer to make it toggle the
// status spinner before and after writes so that they do not collide
type StatusFriendlyWriter struct {
status *Status
inner io.Writer
}
var _ io.Writer = &StatusFriendlyWriter{}
func (ww *StatusFriendlyWriter) Write(p []byte) (n int, err error) {
ww.status.spinner.Stop()
n, err = ww.inner.Write(p)
ww.status.spinner.Start()
return n, err
}
// WrapWriter returns a StatusFriendlyWriter for w
func (s *Status) WrapWriter(w io.Writer) io.Writer {
return &StatusFriendlyWriter{
status: s,
inner: w,
}
}
// WrapLogrus wraps a logrus logger's output with a StatusFriendlyWriter
func (s *Status) WrapLogrus(logger *logrus.Logger) {
logger.SetOutput(s.WrapWriter(logger.Out))
}
// MaybeWrapWriter returns a StatusFriendlyWriter for w IFF w and spinner's
// output are a terminal, otherwise it returns w
func (s *Status) MaybeWrapWriter(w io.Writer) io.Writer {
if IsTerminal(s.spinner.Writer) && IsTerminal(w) {
return s.WrapWriter(w)
}
return w
}
// MaybeWrapLogrus behaves like MaybeWrapWriter for a logrus logger
func (s *Status) MaybeWrapLogrus(logger *logrus.Logger) {
logger.SetOutput(s.MaybeWrapWriter(logger.Out))
}
var spinnerFrames = []string{
"⠈⠁",
"⠈⠑",
"⠈⠱",
"⠈⡱",
"⢀⡱",
"⢄⡱",
"⢄⡱",
"⢆⡱",
"⢎⡱",
"⢎⡰",
"⢎⡠",
"⢎⡀",
"⢎⠁",
"⠎⠁",
"⠊⠁",
}
// IsTerminal returns true if the writer w is a terminal
func IsTerminal(w io.Writer) bool {
if v, ok := (w).(*os.File); ok {
return terminal.IsTerminal(int(v.Fd()))
}
return false
}
// Start starts a new phase of the status, if attached to a terminal
// there will be a loading spinner with this status
func (s *Status) Start(status string) {
s.End(true)
// set new status
isTerm := IsTerminal(s.spinner.Writer)
s.status = status
if isTerm {
s.spinner.Suffix = fmt.Sprintf(" %s ", s.status)
s.spinner.Start()
} else {
fmt.Fprintf(s.spinner.Writer, " • %s ...\n", s.status)
}
}
// End completes the current status, ending any previous spinning and
// marking the status as success or failure
func (s *Status) End(success bool) {
if s.status == "" {
return
}
isTerm := IsTerminal(s.spinner.Writer)
if isTerm {
s.spinner.Stop()
}
if success {
fmt.Fprintf(s.spinner.Writer, " ✓ %s\n", s.status)
} else {
fmt.Fprintf(s.spinner.Writer, " ✗ %s\n", s.status)
}
s.status = ""
}