openshift-install: log debug output to file

This changes the logging strategy so that it logs all output to a local
file in addition to logging at the desired level to the console.
Unfortunately, logrus doesn't have a facility for capturing all log
entries (the hooks are only fired for entries which are at or below the
specified level) so this disables the console output and sets up two
hooks: one for the console and one for the local file.

Author: crawford

.gitignore

@@ -1 +1,2 @@
 bin/
+.openshift-install.log

cmd/openshift-install/create.go

@@ -133,6 +133,12 @@ func newCreateCmd() *cobra.Command {
 
 func runTargetCmd(targets ...asset.WritableAsset) func(cmd *cobra.Command, args []string) error {
 	return func(cmd *cobra.Command, args []string) error {
+		cleanup, err := setupFileHook(rootOpts.dir)
+		if err != nil {
+			return errors.Wrap(err, "failed to setup logging hook")
+		}
+		defer cleanup()
+
 		assetStore, err := asset.NewStore(rootOpts.dir)
 		if err != nil {
 			return errors.Wrapf(err, "failed to create asset store")
@@ -167,6 +173,12 @@ func runTargetCmd(targets ...asset.WritableAsset) func(cmd *cobra.Command, args
 // FIXME: pulling the kubeconfig and metadata out of the root
 // directory is a bit cludgy when we already have them in memory.
 func destroyBootstrap(ctx context.Context, directory string) (err error) {
+	cleanup, err := setupFileHook(rootOpts.dir)
+	if err != nil {
+		return errors.Wrap(err, "failed to setup logging hook")
+	}
+	defer cleanup()
+
 	logrus.Info("Waiting for bootstrap completion...")
 	config, err := clientcmd.BuildConfigFromFlags("", filepath.Join(directory, "auth", "kubeconfig"))
 	if err != nil {

cmd/openshift-install/destroy.go

@@ -43,13 +43,18 @@ func newDestroyClusterCmd() *cobra.Command {
 }
 
 func runDestroyCmd(cmd *cobra.Command, args []string) error {
+	cleanup, err := setupFileHook(rootOpts.dir)
+	if err != nil {
+		return errors.Wrap(err, "failed to setup logging hook")
+	}
+	defer cleanup()
+
 	destroyer, err := destroy.New(logrus.StandardLogger(), rootOpts.dir)
 	if err != nil {
 		return errors.Wrap(err, "Failed while preparing to destroy cluster")
 	}
 	if err := destroyer.Run(); err != nil {
 		return errors.Wrap(err, "Failed to destroy cluster")
-
 	}
 
 	store, err := asset.NewStore(rootOpts.dir)

cmd/openshift-install/log.go

@@ -0,0 +1,72 @@
+package main
+
+import (
+	"io"
+	"os"
+	"path/filepath"
+
+	"github.com/pkg/errors"
+	"github.com/sirupsen/logrus"
+)
+
+type fileHook struct {
+	file      io.Writer
+	formatter logrus.Formatter
+	level     logrus.Level
+}
+
+func newFileHook(file io.Writer, level logrus.Level, formatter logrus.Formatter) *fileHook {
+	return &fileHook{
+		file:      file,
+		formatter: formatter,
+		level:     level,
+	}
+}
+
+func (h fileHook) Levels() []logrus.Level {
+	var levels []logrus.Level
+	for _, level := range logrus.AllLevels {
+		if level <= h.level {
+			levels = append(levels, level)
+		}
+	}
+
+	return levels
+}
+
+func (h *fileHook) Fire(entry *logrus.Entry) error {
+	line, err := h.formatter.Format(entry)
+	if err != nil {
+		return err
+	}
+
+	_, err = h.file.Write(line)
+	return err
+}
+
+func setupFileHook(baseDir string) (func(), error) {
+	if err := os.MkdirAll(baseDir, 0755); err != nil {
+		return nil, errors.Wrap(err, "failed to create base directory for logs")
+	}
+
+	logfile, err := os.OpenFile(filepath.Join(baseDir, ".openshift_install.log"), os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0666)
+	if err != nil {
+		return nil, errors.Wrap(err, "failed to open log file")
+	}
+
+	originalHooks := logrus.LevelHooks{}
+	for k, v := range logrus.StandardLogger().Hooks {
+		originalHooks[k] = v
+	}
+	logrus.AddHook(newFileHook(logfile, logrus.TraceLevel, &logrus.TextFormatter{
+		DisableColors:          true,
+		DisableTimestamp:       false,
+		FullTimestamp:          true,
+		DisableLevelTruncation: false,
+	}))
+
+	return func() {
+		logfile.Close()
+		logrus.StandardLogger().ReplaceHooks(originalHooks)
+	}, nil
+}

cmd/openshift-install/main.go

@@ -1,9 +1,13 @@
 package main
 
 import (
+	"io/ioutil"
+	"os"
+
 	"github.com/pkg/errors"
 	"github.com/sirupsen/logrus"
 	"github.com/spf13/cobra"
+	"golang.org/x/crypto/ssh/terminal"
 )
 
 var (
@@ -50,14 +54,24 @@ func newRootCmd() *cobra.Command {
 }
 
 func runRootCmd(cmd *cobra.Command, args []string) error {
-	logrus.SetFormatter(&logrus.TextFormatter{
-		DisableTimestamp:       true,
-		DisableLevelTruncation: true,
-	})
+	logrus.SetOutput(ioutil.Discard)
+	logrus.SetLevel(logrus.TraceLevel)
+
 	level, err := logrus.ParseLevel(rootOpts.logLevel)
 	if err != nil {
 		return errors.Wrap(err, "invalid log-level")
 	}
-	logrus.SetLevel(level)
+
+	logrus.AddHook(newFileHook(os.Stderr, level, &logrus.TextFormatter{
+		// Setting ForceColors is necessary because logrus.TextFormatter determines
+		// whether or not to enable colors by looking at the output of the logger.
+		// In this case, the output is ioutil.Discard, which is not a terminal.
+		// Overriding it here allows the same check to be done, but against the
+		// hook's output instead of the logger's output.
+		ForceColors:            terminal.IsTerminal(int(os.Stderr.Fd())),
+		DisableTimestamp:       true,
+		DisableLevelTruncation: true,
+	}))
+
 	return nil
 }

docs/user/troubleshooting.md

@@ -88,7 +88,7 @@ This is safe to ignore and merely indicates that the etcd bootstrapping is still
 
 ### Installer Fails to Create Resources
 
-The easiest way to get more debugging information from the installer is to increase the logging level. This can be done by adding `--log-level=debug` to the command line arguments. Of course, this cannot be retroactively applied, so it won't help to debug an installation that has already failed. The installation will have to be attempted again.
+The easiest way to get more debugging information from the installer is to check the log file (`.openshift-install.log`) in the install directory. Regardless of the logging level specified, the installer will write its logs in case they need to be inspected retroactively.
 
 ## Generic Troubleshooting