From 6a18ad9bc509132786e5969f225447b5c432dab8 Mon Sep 17 00:00:00 2001 From: Thomas Stromberg Date: Wed, 13 Feb 2019 21:15:46 -0800 Subject: [PATCH 1/7] Reduce wait times, and wait more consistently --- pkg/util/kubernetes.go | 32 +++++++++++++++++--------------- 1 file changed, 17 insertions(+), 15 deletions(-) diff --git a/pkg/util/kubernetes.go b/pkg/util/kubernetes.go index 927cf1dd7835..0b8df0d0f787 100644 --- a/pkg/util/kubernetes.go +++ b/pkg/util/kubernetes.go @@ -20,8 +20,11 @@ import ( "fmt" "time" + "github.com/golang/glog" "github.com/pkg/errors" - + appsv1 "k8s.io/api/apps/v1" + "k8s.io/api/core/v1" + apierrs "k8s.io/apimachinery/pkg/api/errors" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/fields" "k8s.io/apimachinery/pkg/labels" @@ -29,16 +32,15 @@ import ( "k8s.io/apimachinery/pkg/runtime/schema" "k8s.io/apimachinery/pkg/util/wait" "k8s.io/apimachinery/pkg/watch" - "k8s.io/kubernetes/cmd/kubeadm/app/constants" - - appsv1 "k8s.io/api/apps/v1" - "k8s.io/api/core/v1" - apierrs "k8s.io/apimachinery/pkg/api/errors" "k8s.io/client-go/kubernetes" - - "github.com/golang/glog" "k8s.io/client-go/tools/cache" "k8s.io/client-go/tools/clientcmd" + "k8s.io/kubernetes/cmd/kubeadm/app/constants" +) + +var ( + ReasonableMutateTime = time.Minute * 1 + ReasonableStartTime = time.Minute * 5 ) type PodStore struct { @@ -108,11 +110,11 @@ func StartPods(c kubernetes.Interface, namespace string, pod v1.Pod, waitForRunn return nil } -// Wait up to 10 minutes for all matching pods to become Running and at least one -// matching pod exists. +// WaitForPodsWithLabelRunning waits for all matching pods to become Running and at least one matching pod exists. func WaitForPodsWithLabelRunning(c kubernetes.Interface, ns string, label labels.Selector) error { + glog.Infof("Waiting for pod with label %q in ns %q ...", ns, label) lastKnownPodNumber := -1 - return wait.PollImmediate(constants.APICallRetryInterval, time.Minute*10, func() (bool, error) { + return wait.PollImmediate(constants.APICallRetryInterval, ReasonableStartTime, func() (bool, error) { listOpts := metav1.ListOptions{LabelSelector: label.String()} pods, err := c.CoreV1().Pods(ns).List(listOpts) if err != nil { @@ -139,9 +141,9 @@ func WaitForPodsWithLabelRunning(c kubernetes.Interface, ns string, label labels }) } -// Wait up to 10 minutes for a pod to be deleted +// WaitForPodDelete waits for a pod to be deleted func WaitForPodDelete(c kubernetes.Interface, ns string, label labels.Selector) error { - return wait.PollImmediate(constants.APICallRetryInterval, time.Minute*10, func() (bool, error) { + return wait.PollImmediate(constants.APICallRetryInterval, ReasonableMutateTime, func() (bool, error) { listOpts := metav1.ListOptions{LabelSelector: label.String()} pods, err := c.CoreV1().Pods(ns).List(listOpts) if err != nil { @@ -152,9 +154,9 @@ func WaitForPodDelete(c kubernetes.Interface, ns string, label labels.Selector) }) } -// Wait up to 10 minutes for the given event to appear +// WaitForEvent waits for the given event to appear func WaitForEvent(c kubernetes.Interface, ns string, reason string) error { - return wait.PollImmediate(constants.APICallRetryInterval, time.Minute*10, func() (bool, error) { + return wait.PollImmediate(constants.APICallRetryInterval, ReasonableMutateTime, func() (bool, error) { events, err := c.Events().Events("default").List(metav1.ListOptions{}) if err != nil { glog.Infof("error getting events: %v", err) From 08da5fe3b5fa575dc1df6dd6afd8ced33a7b76a7 Mon Sep 17 00:00:00 2001 From: Thomas Stromberg Date: Wed, 13 Feb 2019 21:29:20 -0800 Subject: [PATCH 2/7] Add pod logs to 'logs' command, show detected problems during minikube start --- cmd/minikube/cmd/logs.go | 57 +++++++- cmd/minikube/cmd/start.go | 42 +++--- pkg/minikube/bootstrapper/bootstrapper.go | 4 +- pkg/minikube/bootstrapper/kubeadm/kubeadm.go | 28 ++-- pkg/minikube/console/style.go | 1 + pkg/minikube/cruntime/containerd.go | 5 + pkg/minikube/cruntime/cri.go | 15 ++ pkg/minikube/cruntime/crio.go | 5 + pkg/minikube/cruntime/cruntime.go | 2 + pkg/minikube/cruntime/docker.go | 15 ++ pkg/minikube/logs/logs.go | 141 +++++++++++++++++++ pkg/minikube/logs/logs_test.go | 44 ++++++ 12 files changed, 313 insertions(+), 46 deletions(-) create mode 100644 pkg/minikube/logs/logs.go create mode 100644 pkg/minikube/logs/logs_test.go diff --git a/cmd/minikube/cmd/logs.go b/cmd/minikube/cmd/logs.go index 4a632d772a0e..fd2b05f567b8 100644 --- a/cmd/minikube/cmd/logs.go +++ b/cmd/minikube/cmd/logs.go @@ -23,13 +23,25 @@ import ( "github.com/spf13/cobra" "github.com/spf13/viper" cmdcfg "k8s.io/minikube/cmd/minikube/cmd/config" - cmdUtil "k8s.io/minikube/cmd/util" + "k8s.io/minikube/pkg/minikube/config" "k8s.io/minikube/pkg/minikube/console" + "k8s.io/minikube/pkg/minikube/cruntime" + "k8s.io/minikube/pkg/minikube/logs" "k8s.io/minikube/pkg/minikube/machine" ) +const ( + // number of problems per log to output + numberOfProblems = 5 +) + var ( - follow bool + // followLogs triggers tail -f mode + followLogs bool + // numberOfLines is how many lines to output, set via -n + numberOfLines int + // showProblems only shows lines that match known issues + showProblems bool ) // logsCmd represents the logs command @@ -38,26 +50,57 @@ var logsCmd = &cobra.Command{ Short: "Gets the logs of the running instance, used for debugging minikube, not user code", Long: `Gets the logs of the running instance, used for debugging minikube, not user code.`, Run: func(cmd *cobra.Command, args []string) { + cfg, err := config.Load() + if err != nil { + console.Fatal("Error getting config: %v", err) + } + api, err := machine.NewAPIClient() if err != nil { console.Fatal("Error getting client: %v", err) os.Exit(1) } defer api.Close() - clusterBootstrapper, err := GetClusterBootstrapper(api, viper.GetString(cmdcfg.Bootstrapper)) + + h, err := api.Load(config.GetMachineName()) + if err != nil { + glog.Exitf("api load: %v", err) + } + runner, err := machine.CommandRunner(h) + if err != nil { + glog.Exitf("command runner: %v", err) + } + bs, err := GetClusterBootstrapper(api, viper.GetString(cmdcfg.Bootstrapper)) if err != nil { glog.Exitf("Error getting cluster bootstrapper: %v", err) } - err = clusterBootstrapper.GetClusterLogsTo(follow, os.Stdout) + cr, err := cruntime.New(cruntime.Config{Type: cfg.KubernetesConfig.ContainerRuntime, Runner: runner}) + if err != nil { + glog.Exitf("Unable to get runtime: %v", err) + } + if followLogs { + err := logs.Follow(cr, bs, runner) + if err != nil { + console.Failure("output: %v", err) + } + return + } + if showProblems { + problems := logs.FindProblems(cr, bs, runner) + logs.OutputProblems(problems, numberOfProblems) + return + } + err = logs.Output(cr, bs, runner, numberOfLines) if err != nil { - console.Fatal("Error getting machine logs:", err) - cmdUtil.MaybeReportErrorAndExit(err) + console.Failure("output: %v", err) } }, } func init() { - logsCmd.Flags().BoolVarP(&follow, "follow", "f", false, "Show only the most recent journal entries, and continuously print new entries as they are appended to the journal.") + logsCmd.Flags().BoolVarP(&followLogs, "follow", "f", false, "Show only the most recent journal entries, and continuously print new entries as they are appended to the journal.") + logsCmd.Flags().BoolVar(&showProblems, "problems", false, "Show only log entries which point to known problems") + logsCmd.Flags().IntVarP(&numberOfLines, "length", "n", 50, "Number of lines back to go within the log") RootCmd.AddCommand(logsCmd) } diff --git a/cmd/minikube/cmd/start.go b/cmd/minikube/cmd/start.go index dba7186966ed..854ed84a5e9c 100644 --- a/cmd/minikube/cmd/start.go +++ b/cmd/minikube/cmd/start.go @@ -45,6 +45,7 @@ import ( "k8s.io/minikube/pkg/minikube/console" "k8s.io/minikube/pkg/minikube/constants" "k8s.io/minikube/pkg/minikube/cruntime" + "k8s.io/minikube/pkg/minikube/logs" "k8s.io/minikube/pkg/minikube/machine" pkgutil "k8s.io/minikube/pkg/util" "k8s.io/minikube/pkg/util/kubeconfig" @@ -186,15 +187,19 @@ func runStart(cmd *cobra.Command, args []string) { if err := saveConfig(config); err != nil { reportErrAndExit("Failed to save config", err) } + runner, err := machine.CommandRunner(host) + if err != nil { + reportErrAndExit("Failed to get command runner", err) + } - configureRuntimes(host) + cr := configureRuntimes(host, runner) bs := prepareHostEnvironment(m, config.KubernetesConfig) waitCacheImages(&cacheGroup) // The kube config must be update must come before bootstrapping, otherwise health checks may use a stale IP kubeconfig := updateKubeConfig(host, &config) - bootstrapCluster(bs, config.KubernetesConfig, preexisting) - validateCluster(bs, ip) + bootstrapCluster(bs, cr, runner, config.KubernetesConfig, preexisting) + validateCluster(bs, cr, runner, ip) configureMounts() if err = LoadCachedImagesInConfigFile(); err != nil { console.Failure("Unable to load cached images from config file.") @@ -451,12 +456,7 @@ func updateKubeConfig(h *host.Host, c *cfg.Config) *kubeconfig.KubeConfigSetup { } // configureRuntimes does what needs to happen to get a runtime going. -func configureRuntimes(h *host.Host) { - runner, err := machine.CommandRunner(h) - if err != nil { - reportErrAndExit("Failed to get command runner", err) - } - +func configureRuntimes(h *host.Host, runner bootstrapper.CommandRunner) cruntime.Manager { config := cruntime.Config{Type: viper.GetString(containerRuntime), Runner: runner} cr, err := cruntime.New(config) if err != nil { @@ -475,7 +475,7 @@ func configureRuntimes(h *host.Host) { if err != nil { cmdutil.MaybeReportErrorAndExit(err) } - + return cr } // waitCacheImages blocks until the image cache jobs complete @@ -490,7 +490,7 @@ func waitCacheImages(g *errgroup.Group) { } // bootstrapCluster starts Kubernetes using the chosen bootstrapper -func bootstrapCluster(bs bootstrapper.Bootstrapper, kc cfg.KubernetesConfig, preexisting bool) { +func bootstrapCluster(bs bootstrapper.Bootstrapper, r cruntime.Manager, runner bootstrapper.CommandRunner, kc cfg.KubernetesConfig, preexisting bool) { console.OutStyle("pulling", "Pulling images used by Kubernetes %s ...", kc.KubernetesVersion) if err := bs.PullImages(kc); err != nil { fmt.Printf("Unable to pull images, which may be OK: %v", err) @@ -501,19 +501,19 @@ func bootstrapCluster(bs bootstrapper.Bootstrapper, kc cfg.KubernetesConfig, pre if preexisting { console.OutStyle("restarting", "Relaunching Kubernetes %s using %s ... ", kc.KubernetesVersion, bsName) if err := bs.RestartCluster(kc); err != nil { - reportErrAndExit("Error restarting cluster", err) + reportProblemsAndExit("Error restarting cluster", err, logs.FindProblems(r, bs, runner)) } return } console.OutStyle("launch", "Launching Kubernetes %s using %s ... ", kc.KubernetesVersion, bsName) if err := bs.StartCluster(kc); err != nil { - reportErrAndExit("Error starting cluster", err) + reportProblemsAndExit("Error starting cluster", err, logs.FindProblems(r, bs, runner)) } } // validateCluster validates that the cluster is well-configured and healthy -func validateCluster(bs bootstrapper.Bootstrapper, ip string) { +func validateCluster(bs bootstrapper.Bootstrapper, r cruntime.Manager, runner bootstrapper.CommandRunner, ip string) { console.OutStyle("verifying-noline", "Verifying component health ...") kStat := func() (err error) { st, err := bs.GetKubeletStatus() @@ -525,7 +525,7 @@ func validateCluster(bs bootstrapper.Bootstrapper, ip string) { } err := pkgutil.RetryAfter(20, kStat, 3*time.Second) if err != nil { - reportErrAndExit("kubelet checks failed", err) + reportProblemsAndExit("kubelet checks failed", err, logs.FindProblems(r, bs, runner)) } aStat := func() (err error) { st, err := bs.GetApiServerStatus(net.ParseIP(ip)) @@ -538,7 +538,7 @@ func validateCluster(bs bootstrapper.Bootstrapper, ip string) { err = pkgutil.RetryAfter(30, aStat, 10*time.Second) if err != nil { - reportErrAndExit("apiserver checks failed", err) + reportProblemsAndExit("apiserver checks failed", err, logs.FindProblems(r, bs, runner)) } console.OutLn("") } @@ -623,9 +623,17 @@ func fatalExit(format string, a ...interface{}) { os.Exit(1) } -// reportFatalExit is a shortcut for outputting an error, reporting it, and exiting. +// reportErrAndExit is a shortcut for outputting an error, reporting it, and exiting. func reportErrAndExit(msg string, err error) { console.Fatal(msg+": %v", err) cmdutil.MaybeReportErrorAndExit(err) os.Exit(1) } + +// reportFatalExit is a shortcut for outputting an error, reporting it, and exiting. +func reportProblemsAndExit(msg string, err error, problems map[string][]string) { + console.Fatal(msg+": %v", err) + logs.OutputProblems(problems, 3) + cmdutil.MaybeReportErrorAndExit(err) + os.Exit(1) +} diff --git a/pkg/minikube/bootstrapper/bootstrapper.go b/pkg/minikube/bootstrapper/bootstrapper.go index 6cd961b18d45..35cb89288a45 100644 --- a/pkg/minikube/bootstrapper/bootstrapper.go +++ b/pkg/minikube/bootstrapper/bootstrapper.go @@ -17,7 +17,6 @@ limitations under the License. package bootstrapper import ( - "io" "net" "k8s.io/minikube/pkg/minikube/config" @@ -32,7 +31,8 @@ type Bootstrapper interface { UpdateCluster(config.KubernetesConfig) error RestartCluster(config.KubernetesConfig) error DeleteCluster(config.KubernetesConfig) error - GetClusterLogsTo(follow bool, out io.Writer) error + // LogCommands returns a map of log type to a command which will display that log. + LogCommands(int, bool) map[string]string SetupCerts(cfg config.KubernetesConfig) error GetKubeletStatus() (string, error) GetApiServerStatus(net.IP) (string, error) diff --git a/pkg/minikube/bootstrapper/kubeadm/kubeadm.go b/pkg/minikube/bootstrapper/kubeadm/kubeadm.go index 1eb4d0fe8fe4..23eb76222227 100644 --- a/pkg/minikube/bootstrapper/kubeadm/kubeadm.go +++ b/pkg/minikube/bootstrapper/kubeadm/kubeadm.go @@ -21,7 +21,6 @@ import ( "crypto" "crypto/tls" "fmt" - "io" "net" "net/http" "os" @@ -121,28 +120,17 @@ func (k *KubeadmBootstrapper) GetApiServerStatus(ip net.IP) (string, error) { return state.Running.String(), nil } -// TODO(r2d4): Should this aggregate all the logs from the control plane? -// Maybe subcommands for each component? minikube logs apiserver? -func (k *KubeadmBootstrapper) GetClusterLogsTo(follow bool, out io.Writer) error { - var flags []string - if follow { - flags = append(flags, "-f") +// LogCommands returns a map of log type to a command which will display that log. +func (k *KubeadmBootstrapper) LogCommands(len int, follow bool) map[string]string { + var kcmd strings.Builder + kcmd.WriteString("journalctl -u kubelet") + if len > 0 { + kcmd.WriteString(fmt.Sprintf(" -n %d", len)) } - logsCommand := fmt.Sprintf("sudo journalctl %s -u kubelet", strings.Join(flags, " ")) - if follow { - if err := k.c.CombinedOutputTo(logsCommand, out); err != nil { - return errors.Wrap(err, "getting cluster logs") + kcmd.WriteString(" -f") } - } else { - - logs, err := k.c.CombinedOutput(logsCommand) - if err != nil { - return errors.Wrap(err, "getting cluster logs") - } - fmt.Fprint(out, logs) - } - return nil + return map[string]string{"kubelet": kcmd.String()} } func (k *KubeadmBootstrapper) StartCluster(k8s config.KubernetesConfig) error { diff --git a/pkg/minikube/console/style.go b/pkg/minikube/console/style.go index 1380769995b5..1e6a18cff7d4 100644 --- a/pkg/minikube/console/style.go +++ b/pkg/minikube/console/style.go @@ -49,6 +49,7 @@ var styles = map[string]style{ "launch": {Prefix: "🚀 "}, "thumbs-up": {Prefix: "👍 "}, "option": {Prefix: " ▪ "}, // Indented bullet + "bullet": {Prefix: " ▪ "}, // Indented bullet "crushed": {Prefix: "💔 "}, // Specialized purpose styles diff --git a/pkg/minikube/cruntime/containerd.go b/pkg/minikube/cruntime/containerd.go index 611197a3b598..e46a30e5daa9 100644 --- a/pkg/minikube/cruntime/containerd.go +++ b/pkg/minikube/cruntime/containerd.go @@ -107,3 +107,8 @@ func (r *Containerd) KillContainers(ids []string) error { func (r *Containerd) StopContainers(ids []string) error { return stopCRIContainers(r.Runner, ids) } + +// ContainerLogCmd returns the command to retrieve the log for a container based on ID +func (r *Containerd) ContainerLogCmd(id string, len int, follow bool) string { + return criContainerLogCmd(id, len, follow) +} diff --git a/pkg/minikube/cruntime/cri.go b/pkg/minikube/cruntime/cri.go index 67f4595ef0dd..0ccc7bfa57e3 100644 --- a/pkg/minikube/cruntime/cri.go +++ b/pkg/minikube/cruntime/cri.go @@ -60,3 +60,18 @@ image-endpoint: unix://{{.Socket}} } return cr.Run(fmt.Sprintf("sudo mkdir -p %s && printf %%s \"%s\" | sudo tee %s", path.Dir(cPath), b.String(), cPath)) } + +// criContainerLogCmd returns the command to retrieve the log for a container based on ID +func criContainerLogCmd(id string, len int, follow bool) string { + var cmd strings.Builder + cmd.WriteString("crictl logs ") + if len > 0 { + cmd.WriteString(fmt.Sprintf("--tail %d ", len)) + } + if follow { + cmd.WriteString("--follow ") + } + + cmd.WriteString(id) + return cmd.String() +} diff --git a/pkg/minikube/cruntime/crio.go b/pkg/minikube/cruntime/crio.go index 2897dd2c06d5..93aa426ddf3d 100644 --- a/pkg/minikube/cruntime/crio.go +++ b/pkg/minikube/cruntime/crio.go @@ -106,3 +106,8 @@ func (r *CRIO) KillContainers(ids []string) error { func (r *CRIO) StopContainers(ids []string) error { return stopCRIContainers(r.Runner, ids) } + +// ContainerLogCmd returns the command to retrieve the log for a container based on ID +func (r *CRIO) ContainerLogCmd(id string, len int, follow bool) string { + return criContainerLogCmd(id, len, follow) +} diff --git a/pkg/minikube/cruntime/cruntime.go b/pkg/minikube/cruntime/cruntime.go index 9f478086164d..fe670c29e517 100644 --- a/pkg/minikube/cruntime/cruntime.go +++ b/pkg/minikube/cruntime/cruntime.go @@ -61,6 +61,8 @@ type Manager interface { KillContainers([]string) error // StopContainers stops containers based on ID StopContainers([]string) error + // ContainerLogCmd returns the command to retrieve the log for a container based on ID + ContainerLogCmd(string, int, bool) string } // Config is runtime configuration diff --git a/pkg/minikube/cruntime/docker.go b/pkg/minikube/cruntime/docker.go index 92f4c0bb5485..f70a513603da 100644 --- a/pkg/minikube/cruntime/docker.go +++ b/pkg/minikube/cruntime/docker.go @@ -101,3 +101,18 @@ func (r *Docker) KillContainers(ids []string) error { func (r *Docker) StopContainers(ids []string) error { return r.Runner.Run(fmt.Sprintf("docker stop %s", strings.Join(ids, " "))) } + +// ContainerLogCmd returns the command to retrieve the log for a container based on ID +func (r *Docker) ContainerLogCmd(id string, len int, follow bool) string { + var cmd strings.Builder + cmd.WriteString("docker logs ") + if len > 0 { + cmd.WriteString(fmt.Sprintf("--tail %d ", len)) + } + if follow { + cmd.WriteString("--follow ") + } + + cmd.WriteString(id) + return cmd.String() +} diff --git a/pkg/minikube/logs/logs.go b/pkg/minikube/logs/logs.go new file mode 100644 index 000000000000..95c6c4d89101 --- /dev/null +++ b/pkg/minikube/logs/logs.go @@ -0,0 +1,141 @@ +/* +Copyright 2019 The Kubernetes Authors All rights reserved. + +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 logs are convenience methods for fetching logs from a minikube cluster +package logs + +import ( + "fmt" + "os" + "regexp" + "sort" + "strings" + + "github.com/docker/machine/libmachine/log" + "github.com/golang/glog" + "k8s.io/minikube/pkg/minikube/bootstrapper" + "k8s.io/minikube/pkg/minikube/console" + "k8s.io/minikube/pkg/minikube/cruntime" +) + +// rootCauseRe is a regular expression that matches known failure root causes +var rootCauseRe = regexp.MustCompile(`^error: |eviction manager: pods.* evicted|unknown flag: --`) + +// importantPods are a list of pods to retrieve logs for, in addition to the bootstrapper logs. +var importantPods = []string{ + "k8s_kube-apiserver", + "k8s_coredns_coredns", + "k8s_kube-scheduler", +} + +// Follow follows logs from multiple files in tail(1) format +func Follow(r cruntime.Manager, bs bootstrapper.Bootstrapper, runner bootstrapper.CommandRunner) error { + cs := []string{} + for _, v := range logCommands(r, bs, 0, true) { + cs = append(cs, v+" &") + } + cs = append(cs, "wait") + return runner.CombinedOutputTo(strings.Join(cs, " "), os.Stdout) +} + +// IsProblem returns whether this line matches a known problem +func IsProblem(line string) bool { + return rootCauseRe.MatchString(line) +} + +// FindProblems finds possible root causes among the logs +func FindProblems(r cruntime.Manager, bs bootstrapper.Bootstrapper, runner bootstrapper.CommandRunner) map[string][]string { + pMap := map[string][]string{} + cmds := logCommands(r, bs, 200, false) + for name, cmd := range cmds { + log.Infof("Gathering logs for %s ...", name) + out, err := runner.CombinedOutput(cmds[name]) + if err != nil { + glog.Warningf("failed %s: %s: %v", name, cmd, err) + continue + } + log.Infof("log length: %d", len(out)) + + problems := []string{} + for _, l := range strings.Split(out, "\n") { + if IsProblem(l) { + glog.Warningf("Found %s problem: %s", name, l) + problems = append(problems, l) + } + } + if len(problems) > 0 { + pMap[name] = problems + } + } + return pMap +} + +// OutputProblems outputs discovered problems. +func OutputProblems(problems map[string][]string, maxLines int) { + for name, lines := range problems { + console.OutStyle("failure", "Problem detected in %q", name) + if len(lines) > maxLines { + lines = lines[len(lines)-maxLines:] + } + for _, l := range lines { + console.OutStyle("bullet", l) + } + } +} + +// Output displays logs from multiple sources in tail(1) format +func Output(r cruntime.Manager, bs bootstrapper.Bootstrapper, runner bootstrapper.CommandRunner, lines int) error { + cmds := logCommands(r, bs, lines, false) + names := []string{} + for k := range cmds { + names = append(names, k) + } + sort.Strings(names) + + failed := []string{} + for _, name := range names { + console.OutLn("==> %s <==", name) + out, err := runner.CombinedOutput(cmds[name]) + if err != nil { + glog.Errorf("failed: %v", err) + failed = append(failed, name) + continue + } + console.OutLn(out) + } + if len(failed) > 0 { + return fmt.Errorf("unable to fetch logs for: %s", strings.Join(failed, ", ")) + } + return nil +} + +// logCommands returns a list of commands that would be run to receive the anticipated logs +func logCommands(r cruntime.Manager, bs bootstrapper.Bootstrapper, length int, follow bool) map[string]string { + cmds := bs.LogCommands(length, follow) + for _, pod := range importantPods { + ids, err := r.ListContainers(pod) + if err != nil { + glog.Errorf("Failed to list containers for %q: %v", pod, err) + continue + } + if len(ids) == 0 { + glog.Errorf("No containers found matching %q", pod) + continue + } + cmds[pod] = r.ContainerLogCmd(ids[0], length, follow) + } + return cmds +} diff --git a/pkg/minikube/logs/logs_test.go b/pkg/minikube/logs/logs_test.go new file mode 100644 index 000000000000..5e1405acecaf --- /dev/null +++ b/pkg/minikube/logs/logs_test.go @@ -0,0 +1,44 @@ +/* +Copyright 2019 The Kubernetes Authors All rights reserved. + +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 logs + +import ( + "testing" +) + +func TestIsProblem(t *testing.T) { + var tests = []struct { + name string + want bool + input string + }{ + {"almost", false, "F2350 I would love to be an unknown flag, but I am not -- :( --"}, + {"apiserver-required-flag #1962", true, "error: [service-account-issuer is a required flag when BoundServiceAccountTokenVolume is enabled, --service-account-signing-key-file and --service-account-issuer are required flags"}, + {"kubelet-eviction #", true, "I0213 07:16:44.041623 2410 eviction_manager.go:187] eviction manager: pods kube-apiserver-minikube_kube-system(87f41e2e0629c3deb5c2239e08d8045d) evicted, waiting for pod to be cleaned up"}, + {"kubelet-unknown-flag #3655", true, "F0212 14:55:46.443031 2693 server.go:148] unknown flag: --AllowedUnsafeSysctls"}, + {"apiserver-auth-mode #2852", true, `{"log":"Error: unknown flag: --Authorization.Mode\n","stream":"stderr","time":"2018-06-17T22:16:35.134161966Z"}`}, + {"apiserver-admmission #3524", true, "error: unknown flag: --GenericServerRunOptions.AdmissionControl"}, + } + for _, tc := range tests { + t.Run(tc.name, func(t *testing.T) { + got := IsProblem(tc.input) + if got != tc.want { + t.Fatalf("IsProblem(%s)=%v, want %v", tc.input, got, tc.want) + } + }) + } +} From 496bbe00bba09ac8e4c31c9b68dfdc62bcc20380 Mon Sep 17 00:00:00 2001 From: Thomas Stromberg Date: Wed, 13 Feb 2019 21:35:42 -0800 Subject: [PATCH 3/7] Pluralize problem --- pkg/minikube/logs/logs.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pkg/minikube/logs/logs.go b/pkg/minikube/logs/logs.go index 95c6c4d89101..64a12ed3da63 100644 --- a/pkg/minikube/logs/logs.go +++ b/pkg/minikube/logs/logs.go @@ -86,7 +86,7 @@ func FindProblems(r cruntime.Manager, bs bootstrapper.Bootstrapper, runner boots // OutputProblems outputs discovered problems. func OutputProblems(problems map[string][]string, maxLines int) { for name, lines := range problems { - console.OutStyle("failure", "Problem detected in %q", name) + console.OutStyle("failure", "Problems detected in %q:", name) if len(lines) > maxLines { lines = lines[len(lines)-maxLines:] } From 247e957e8ff30b1ed0213613a4dad2297e198923 Mon Sep 17 00:00:00 2001 From: Thomas Stromberg Date: Wed, 13 Feb 2019 21:47:54 -0800 Subject: [PATCH 4/7] Revert accidental indentation --- pkg/minikube/bootstrapper/kubeadm/kubeadm.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pkg/minikube/bootstrapper/kubeadm/kubeadm.go b/pkg/minikube/bootstrapper/kubeadm/kubeadm.go index 76872a125b2d..60ca50c622db 100644 --- a/pkg/minikube/bootstrapper/kubeadm/kubeadm.go +++ b/pkg/minikube/bootstrapper/kubeadm/kubeadm.go @@ -129,7 +129,7 @@ func (k *KubeadmBootstrapper) LogCommands(len int, follow bool) map[string]strin } if follow { kcmd.WriteString(" -f") - } + } return map[string]string{"kubelet": kcmd.String()} } From 4c2ba194558c9fddb71010922005d93ebc811ac2 Mon Sep 17 00:00:00 2001 From: Balint Pato Date: Thu, 14 Feb 2019 13:16:57 -0800 Subject: [PATCH 5/7] Update pkg/minikube/logs/logs_test.go Co-Authored-By: tstromberg --- pkg/minikube/logs/logs_test.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pkg/minikube/logs/logs_test.go b/pkg/minikube/logs/logs_test.go index 5e1405acecaf..245f5aa4d384 100644 --- a/pkg/minikube/logs/logs_test.go +++ b/pkg/minikube/logs/logs_test.go @@ -31,7 +31,7 @@ func TestIsProblem(t *testing.T) { {"kubelet-eviction #", true, "I0213 07:16:44.041623 2410 eviction_manager.go:187] eviction manager: pods kube-apiserver-minikube_kube-system(87f41e2e0629c3deb5c2239e08d8045d) evicted, waiting for pod to be cleaned up"}, {"kubelet-unknown-flag #3655", true, "F0212 14:55:46.443031 2693 server.go:148] unknown flag: --AllowedUnsafeSysctls"}, {"apiserver-auth-mode #2852", true, `{"log":"Error: unknown flag: --Authorization.Mode\n","stream":"stderr","time":"2018-06-17T22:16:35.134161966Z"}`}, - {"apiserver-admmission #3524", true, "error: unknown flag: --GenericServerRunOptions.AdmissionControl"}, + {"apiserver-admission #3524", true, "error: unknown flag: --GenericServerRunOptions.AdmissionControl"}, } for _, tc := range tests { t.Run(tc.name, func(t *testing.T) { From 5029f8a66e61022b36ebe4fe7629cb4441d139a5 Mon Sep 17 00:00:00 2001 From: Balint Pato Date: Thu, 14 Feb 2019 13:17:32 -0800 Subject: [PATCH 6/7] Update pkg/minikube/exit/exit.go Co-Authored-By: tstromberg --- pkg/minikube/exit/exit.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pkg/minikube/exit/exit.go b/pkg/minikube/exit/exit.go index f599832703fc..971426ad37d4 100644 --- a/pkg/minikube/exit/exit.go +++ b/pkg/minikube/exit/exit.go @@ -63,7 +63,7 @@ func WithError(msg string, err error) { os.Exit(Software) } -// WithError outputs an error along with any autodetected problems, and exits. +// WithProblems outputs an error along with any autodetected problems, and exits. func WithProblems(msg string, err error, problems map[string][]string) { displayError(msg, err) From 45303bac07a24b1faa4ac20216504981637f4e6b Mon Sep 17 00:00:00 2001 From: Thomas Stromberg Date: Thu, 14 Feb 2019 13:59:08 -0800 Subject: [PATCH 7/7] Code review comments --- pkg/minikube/bootstrapper/bootstrapper.go | 10 +++++- pkg/minikube/bootstrapper/kubeadm/kubeadm.go | 8 ++--- pkg/minikube/exit/exit.go | 5 +-- pkg/minikube/logs/logs.go | 33 +++++++++++++------- 4 files changed, 38 insertions(+), 18 deletions(-) diff --git a/pkg/minikube/bootstrapper/bootstrapper.go b/pkg/minikube/bootstrapper/bootstrapper.go index 35cb89288a45..4140f58548a9 100644 --- a/pkg/minikube/bootstrapper/bootstrapper.go +++ b/pkg/minikube/bootstrapper/bootstrapper.go @@ -23,6 +23,14 @@ import ( "k8s.io/minikube/pkg/minikube/constants" ) +// LogOptions are options to be passed to LogCommands +type LogOptions struct { + // Lines is the number of recent log lines to include, as in tail -n. + Lines int + // Follow is whether or not to actively follow the logs, as in tail -f. + Follow bool +} + // Bootstrapper contains all the methods needed to bootstrap a kubernetes cluster type Bootstrapper interface { // PullImages pulls images necessary for a cluster. Success should not be required. @@ -32,7 +40,7 @@ type Bootstrapper interface { RestartCluster(config.KubernetesConfig) error DeleteCluster(config.KubernetesConfig) error // LogCommands returns a map of log type to a command which will display that log. - LogCommands(int, bool) map[string]string + LogCommands(LogOptions) map[string]string SetupCerts(cfg config.KubernetesConfig) error GetKubeletStatus() (string, error) GetApiServerStatus(net.IP) (string, error) diff --git a/pkg/minikube/bootstrapper/kubeadm/kubeadm.go b/pkg/minikube/bootstrapper/kubeadm/kubeadm.go index 60ca50c622db..f5f4a8e3fcbf 100644 --- a/pkg/minikube/bootstrapper/kubeadm/kubeadm.go +++ b/pkg/minikube/bootstrapper/kubeadm/kubeadm.go @@ -121,13 +121,13 @@ func (k *KubeadmBootstrapper) GetApiServerStatus(ip net.IP) (string, error) { } // LogCommands returns a map of log type to a command which will display that log. -func (k *KubeadmBootstrapper) LogCommands(len int, follow bool) map[string]string { +func (k *KubeadmBootstrapper) LogCommands(o bootstrapper.LogOptions) map[string]string { var kcmd strings.Builder kcmd.WriteString("journalctl -u kubelet") - if len > 0 { - kcmd.WriteString(fmt.Sprintf(" -n %d", len)) + if o.Lines > 0 { + kcmd.WriteString(fmt.Sprintf(" -n %d", o.Lines)) } - if follow { + if o.Follow { kcmd.WriteString(" -f") } return map[string]string{"kubelet": kcmd.String()} diff --git a/pkg/minikube/exit/exit.go b/pkg/minikube/exit/exit.go index 971426ad37d4..fad5b18df386 100644 --- a/pkg/minikube/exit/exit.go +++ b/pkg/minikube/exit/exit.go @@ -18,6 +18,7 @@ limitations under the License. package exit import ( + "fmt" "os" "github.com/golang/glog" @@ -80,10 +81,10 @@ func WithProblems(msg string, err error, problems map[string][]string) { } func displayError(msg string, err error) { + // use Warning because Error will display a duplicate message to stderr + glog.Warningf(fmt.Sprintf("%s: %v", msg, err)) console.Fatal(msg+": %v", err) console.Err("\n") console.ErrStyle("sad", "Sorry that minikube crashed. If this was unexpected, we would love to hear from you:") console.ErrStyle("url", "https://github.com/kubernetes/minikube/issues/new") - // use Warning because Error will display a duplicate message to stderr - glog.Warningf(msg+"%s: %v", msg) } diff --git a/pkg/minikube/logs/logs.go b/pkg/minikube/logs/logs.go index 7cca818d6c80..11f63e90137d 100644 --- a/pkg/minikube/logs/logs.go +++ b/pkg/minikube/logs/logs.go @@ -18,13 +18,14 @@ limitations under the License. package logs import ( + "bufio" + "bytes" "fmt" "os" "regexp" "sort" "strings" - "github.com/docker/machine/libmachine/log" "github.com/golang/glog" "k8s.io/minikube/pkg/minikube/bootstrapper" "k8s.io/minikube/pkg/minikube/console" @@ -41,6 +42,10 @@ var importantPods = []string{ "k8s_kube-scheduler", } +// lookbackwardsCount is how far back to look in a log for problems. This should be large enough to +// include usage messages from a failed binary, but small enough to not include irrelevant problems. +const lookBackwardsCount = 200 + // Follow follows logs from multiple files in tail(1) format func Follow(r cruntime.Manager, bs bootstrapper.Bootstrapper, runner bootstrapper.CommandRunner) error { cs := []string{} @@ -59,18 +64,19 @@ func IsProblem(line string) bool { // FindProblems finds possible root causes among the logs func FindProblems(r cruntime.Manager, bs bootstrapper.Bootstrapper, runner bootstrapper.CommandRunner) map[string][]string { pMap := map[string][]string{} - cmds := logCommands(r, bs, 200, false) + cmds := logCommands(r, bs, lookBackwardsCount, false) for name, cmd := range cmds { - log.Infof("Gathering logs for %s ...", name) - out, err := runner.CombinedOutput(cmds[name]) + glog.Infof("Gathering logs for %s ...", name) + var b bytes.Buffer + err := runner.CombinedOutputTo(cmds[name], &b) if err != nil { glog.Warningf("failed %s: %s: %v", name, cmd, err) continue } - log.Infof("log length: %d", len(out)) - + scanner := bufio.NewScanner(&b) problems := []string{} - for _, l := range strings.Split(out, "\n") { + for scanner.Scan() { + l := scanner.Text() if IsProblem(l) { glog.Warningf("Found %s problem: %s", name, l) problems = append(problems, l) @@ -108,13 +114,17 @@ func Output(r cruntime.Manager, bs bootstrapper.Bootstrapper, runner bootstrappe failed := []string{} for _, name := range names { console.OutLn("==> %s <==", name) - out, err := runner.CombinedOutput(cmds[name]) + var b bytes.Buffer + err := runner.CombinedOutputTo(cmds[name], &b) if err != nil { glog.Errorf("failed: %v", err) failed = append(failed, name) continue } - console.OutLn(out) + scanner := bufio.NewScanner(&b) + for scanner.Scan() { + console.OutLn(scanner.Text()) + } } if len(failed) > 0 { return fmt.Errorf("unable to fetch logs for: %s", strings.Join(failed, ", ")) @@ -124,15 +134,16 @@ func Output(r cruntime.Manager, bs bootstrapper.Bootstrapper, runner bootstrappe // logCommands returns a list of commands that would be run to receive the anticipated logs func logCommands(r cruntime.Manager, bs bootstrapper.Bootstrapper, length int, follow bool) map[string]string { - cmds := bs.LogCommands(length, follow) + cmds := bs.LogCommands(bootstrapper.LogOptions{Lines: length, Follow: follow}) for _, pod := range importantPods { ids, err := r.ListContainers(pod) if err != nil { glog.Errorf("Failed to list containers for %q: %v", pod, err) continue } + glog.Infof("%d containers: %s", len(ids), ids) if len(ids) == 0 { - glog.Errorf("No containers found matching %q", pod) + cmds[pod] = fmt.Sprintf("No container was found matching %q", pod) continue } cmds[pod] = r.ContainerLogCmd(ids[0], length, follow)