Merge pull request #2111 from kinvolk/ckuehl/stage1-dont-supress-errors

stage1: don't suppress error output

CHANGELOG.md

@@ -20,6 +20,7 @@
 
 - Fix regression when authenticating to v2 Docker registries ([#2008](https://github.com/coreos/rkt/issues/2008)).
 - Don't link to libacl, but dlopen it ([#1963](https://github.com/coreos/rkt/pull/1963)). This means that rkt will not crash if libacl is not present on the host, but it will just print a warning.
+- Only suppress diagnostic messages, not error messages in stage1 ([#2111](https://github.com/coreos/rkt/pull/2111)).
 
 #### Other changes
 

pkg/log/log.go

@@ -19,6 +19,7 @@ import (
 	"fmt"
 	"io"
 	"log"
+	"os"
 	"strings"
 
 	"github.com/hashicorp/errwrap"
@@ -40,6 +41,20 @@ func New(out io.Writer, prefix string, debug bool) *Logger {
 	return l
 }
 
+// NewLogSet returns a set of Loggers for commonly used output streams: errors,
+// diagnostics, stdout. The error and stdout streams should generally never be
+// suppressed. diagnostic can be suppressed by setting the output to
+// ioutil.Discard. If an output destination is not needed, one can simply
+// discard it by assigning it to '_'.
+func NewLogSet(prefix string, debug bool) (stderr, diagnostic, stdout *Logger) {
+	stderr = New(os.Stderr, prefix, debug)
+	diagnostic = New(os.Stderr, prefix, debug)
+	// Debug not used for stdout.
+	stdout = New(os.Stdout, prefix, false)
+
+	return stderr, diagnostic, stdout
+}
+
 // SetDebug sets the debug flag to the value of b
 func (l *Logger) SetDebug(b bool) { l.debug = b }
 

stage1/enter_kvm/enter_kvm.go

@@ -47,6 +47,7 @@ var (
 	sshPath string
 	u, _    = user.Current()
 	log     *rktlog.Logger
+	diag    *rktlog.Logger
 )
 
 // fileAccessible checks if the given path exists and is a regular file
@@ -140,7 +141,7 @@ func init() {
 	flag.StringVar(&podPid, "pid", "", "podPID")
 	flag.StringVar(&appName, "appname", "", "application to use")
 
-	log = rktlog.New(os.Stderr, "kvm", false)
+	log, diag, _ = rktlog.NewLogSet("kvm", false)
 
 	var err error
 	if sshPath, err = exec.LookPath("ssh"); err != nil {
@@ -237,10 +238,11 @@ func execSSH() error {
 func main() {
 	flag.Parse()
 
+	log.SetDebug(debug)
+	diag.SetDebug(debug)
+
 	if !debug {
-		log.SetOutput(ioutil.Discard)
-	} else {
-		log.SetDebug(true)
+		diag.SetOutput(ioutil.Discard)
 	}
 
 	if appName == "" {

stage1/init/common/kvm_mount.go

@@ -86,7 +86,7 @@ func installNewMountUnit(root, what, where, fsType, options, beforeAndrequiredBy
 	if err := writeUnit(opts, filepath.Join(unitsPath, unitName)); err != nil {
 		return "", err
 	}
-	log.Printf("mount unit created: %q in %q (what=%q, where=%q)", unitName, unitsPath, what, where)
+	diag.Printf("mount unit created: %q in %q (what=%q, where=%q)", unitName, unitsPath, what, where)
 
 	return unitName, nil
 }
@@ -170,7 +170,7 @@ func AppToSystemdMountUnits(root string, appName types.ACName, volumes []types.V
 		whatFullPath := filepath.Join(root, whatPath)
 
 		if vol.Kind == "empty" {
-			log.Printf("creating an empty volume folder for sharing: %q", whatFullPath)
+			diag.Printf("creating an empty volume folder for sharing: %q", whatFullPath)
 			err := os.MkdirAll(whatFullPath, 0700)
 			if err != nil {
 				return err
@@ -182,13 +182,13 @@ func AppToSystemdMountUnits(root string, appName types.ACName, volumes []types.V
 		whereFullPath := filepath.Join(root, wherePath)
 
 		// assertion to make sure that "what" exists (created earlier by PodToSystemdHostMountUnits)
-		log.Printf("checking required source path: %q", whatFullPath)
+		diag.Printf("checking required source path: %q", whatFullPath)
 		if _, err := os.Stat(whatFullPath); os.IsNotExist(err) {
 			return fmt.Errorf("bug: missing source for volume %v", vol.Name)
 		}
 
 		// optionally prepare app directory
-		log.Printf("optionally preparing destination path: %q", whereFullPath)
+		diag.Printf("optionally preparing destination path: %q", whereFullPath)
 		err := os.MkdirAll(whereFullPath, 0700)
 		if err != nil {
 			return errwrap.Wrap(fmt.Errorf("failed to prepare dir for mount %v", m.Volume), err)
@@ -241,7 +241,7 @@ func VolumesToKvmDiskArgs(volumes []types.Volume) []string {
 		if vol.Kind == "host" {
 			// eg. --9p=/home/jon/srcdir,tag
 			arg := "--9p=" + vol.Source + "," + mountTag
-			log.Printf("--disk argument: %#v", arg)
+			diag.Printf("--disk argument: %#v", arg)
 			args = append(args, arg)
 		}
 	}

stage1/init/common/log.go

@@ -15,13 +15,25 @@
 package common
 
 import (
-	"os"
+	"io/ioutil"
 
 	rktlog "github.com/coreos/rkt/pkg/log"
 )
 
-var log *rktlog.Logger
+var (
+	log  *rktlog.Logger
+	diag *rktlog.Logger
+)
 
 func init() {
-	log = rktlog.New(os.Stderr, "stage1", false)
+	log, diag, _ = rktlog.NewLogSet("stage1", false)
+}
+
+func InitDebug(debug bool) {
+	log.SetDebug(debug)
+	if debug {
+		diag.SetDebug(true)
+	} else {
+		diag.SetOutput(ioutil.Discard)
+	}
 }

stage1/init/init.go

@@ -104,6 +104,7 @@ var (
 	localhostIP  net.IP
 	localConfig  string
 	log          *rktlog.Logger
+	diag         *rktlog.Logger
 )
 
 func init() {
@@ -468,7 +469,7 @@ func forwardedPorts(pod *stage1commontypes.Pod) ([]networking.ForwardedPort, err
 func stage1() int {
 	uuid, err := types.NewUUID(flag.Arg(0))
 	if err != nil {
-		log.Print("UUID is missing or malformed")
+		log.PrintE("UUID is missing or malformed", err)
 		return 1
 	}
 
@@ -735,9 +736,11 @@ func getContainerSubCgroup(machineID string) (string, error) {
 func main() {
 	flag.Parse()
 
-	log = rktlog.New(os.Stderr, "stage1", debug)
+	stage1initcommon.InitDebug(debug)
+
+	log, diag, _ = rktlog.NewLogSet("stage1", debug)
 	if !debug {
-		log.SetOutput(ioutil.Discard)
+		diag.SetOutput(ioutil.Discard)
 	}
 
 	// move code into stage1() helper so deferred fns get run

stage1_fly/gc/main.go

@@ -29,7 +29,7 @@ const (
 var (
 	debug bool
 
-	log *rktlog.Logger
+	diag *rktlog.Logger
 )
 
 func init() {
@@ -39,10 +39,10 @@ func init() {
 func main() {
 	flag.Parse()
 
-	log = rktlog.New(os.Stderr, "gc", debug)
+	diag = rktlog.New(os.Stderr, "gc", debug)
 	if !debug {
-		log.SetOutput(ioutil.Discard)
+		diag.SetOutput(ioutil.Discard)
 	}
-	log.Printf("not doing anything since stage0 is cleaning up the mounts")
+	diag.Printf("not doing anything since stage0 is cleaning up the mounts")
 	return
 }

stage1_fly/run/main.go

@@ -60,7 +60,8 @@ var (
 	discardBool    bool
 	discardString  string
 
-	log *rktlog.Logger
+	log  *rktlog.Logger
+	diag *rktlog.Logger
 )
 
 func getHostMounts() (map[string]struct{}, error) {
@@ -117,7 +118,7 @@ func evaluateMounts(rfs string, app string, p *stage1commontypes.Pod) ([]flyMoun
 			return nil, fmt.Errorf("duplicate mount given: %q", m.Volume)
 		}
 		namedVolumeMounts[m.Volume] = volumeMountTuple{M: m}
-		log.Printf("adding %+v", namedVolumeMounts[m.Volume])
+		diag.Printf("adding %+v", namedVolumeMounts[m.Volume])
 	}
 
 	// Merge command-line Mounts with ImageManifest's MountPoints
@@ -128,7 +129,7 @@ func evaluateMounts(rfs string, app string, p *stage1commontypes.Pod) ([]flyMoun
 			return nil, fmt.Errorf("conflicting path information from mount and mountpoint %q", mp.Name)
 		case !exists:
 			namedVolumeMounts[mp.Name] = volumeMountTuple{M: schema.Mount{Volume: mp.Name, Path: mp.Path}}
-			log.Printf("adding %+v", namedVolumeMounts[mp.Name])
+			diag.Printf("adding %+v", namedVolumeMounts[mp.Name])
 		}
 	}
 
@@ -143,7 +144,7 @@ func evaluateMounts(rfs string, app string, p *stage1commontypes.Pod) ([]flyMoun
 			return nil, fmt.Errorf("mismatched volume:mount pair: %q != %q", v.Name, tuple.M.Volume)
 		}
 		namedVolumeMounts[v.Name] = volumeMountTuple{V: v, M: tuple.M}
-		log.Printf("adding %+v", namedVolumeMounts[v.Name])
+		diag.Printf("adding %+v", namedVolumeMounts[v.Name])
 	}
 
 	// Merge command-line Volumes with ImageManifest's MountPoints
@@ -159,7 +160,7 @@ func evaluateMounts(rfs string, app string, p *stage1commontypes.Pod) ([]flyMoun
 			v := tuple.V
 			v.ReadOnly = &mp.ReadOnly
 			namedVolumeMounts[mp.Name] = volumeMountTuple{M: tuple.M, V: v}
-			log.Printf("adding %+v", namedVolumeMounts[mp.Name])
+			diag.Printf("adding %+v", namedVolumeMounts[mp.Name])
 		}
 	}
 
@@ -317,7 +318,7 @@ func stage1() int {
 		return 4
 	}
 
-	log.Printf("chroot to %q", rfs)
+	diag.Printf("chroot to %q", rfs)
 	if err := syscall.Chroot(rfs); err != nil {
 		log.PrintE("can't chroot", err)
 		return 1
@@ -328,7 +329,7 @@ func stage1() int {
 		return 1
 	}
 
-	log.Printf("execing %q in %q", args, rfs)
+	diag.Printf("execing %q in %q", args, rfs)
 	err = stage1common.WithClearedCloExec(lfd, func() error {
 		return syscall.Exec(args[0], args, env)
 	})
@@ -343,9 +344,9 @@ func stage1() int {
 func main() {
 	flag.Parse()
 
-	log = rktlog.New(os.Stderr, "run", debug)
+	log, diag, _ = rktlog.NewLogSet("run", debug)
 	if !debug {
-		log.SetOutput(ioutil.Discard)
+		diag.SetOutput(ioutil.Discard)
 	}
 
 	// move code into stage1() helper so defered fns get run

tests/rkt_error_output_test.go

@@ -0,0 +1,37 @@
+// Copyright 2016 The rkt 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 main
+
+import (
+	"fmt"
+	"os"
+	"testing"
+
+	"github.com/coreos/rkt/tests/testutils"
+)
+
+func TestRktEnsureErrors(t *testing.T) {
+	const imgName = "rkt-ensure-errors-test"
+
+	image := patchTestACI(fmt.Sprintf("%s.aci", imgName), fmt.Sprintf("--name=%s", imgName))
+	defer os.Remove(image)
+
+	ctx := testutils.NewRktRunCtx()
+	defer ctx.Cleanup()
+
+	runCmd := fmt.Sprintf("%s run --insecure-options=image --net=notavalidnetwork %s", ctx.Cmd(), image)
+	t.Logf("Running test: %s", runCmd)
+	runRktAndCheckRegexOutput(t, runCmd, "stage1: failed to setup network")
+}