qemu.go, harness.go: Add CheckConsoleForBadness & CheckConsoleText

CheckConsoleForBadness reads output from a journal pipe and checks
each line for "badness". It then calls CheckConsoleText to
analyze lines of Console output.

Ref: coreos#3788

mantle/cmd/kola/testiso.go

@@ -679,6 +679,23 @@ func awaitCompletion(ctx context.Context, inst *platform.QemuInstance, outdir st
 				errchan <- err
 			}
 		}()
+		go func() {
+			// check for console badness
+			errBuf, err := inst.CheckConsoleForBadness(ctx)
+			if err == nil {
+				if errBuf != "" {
+					plog.Info("entered emergency.target in initramfs")
+					path := filepath.Join(outdir, "ignition-virtio-dump.txt")
+					if err := os.WriteFile(path, []byte(errBuf), 0644); err != nil {
+						plog.Errorf("Failed to write journal: %v", err)
+					}
+					err = platform.ErrInitramfsEmergency
+				}
+			}
+			if err != nil {
+				errchan <- err
+			}
+		}()
 	}
 	go func() {
 		err := inst.Wait()

mantle/kola/harness.go

@@ -1917,6 +1917,27 @@ func ScpKolet(machines []platform.Machine) error {
 	return fmt.Errorf("Unable to locate kolet binary for %s", mArch)
 }
 
+// CheckConsoleText checks console output for badness
+func CheckConsoleText(consoleOutput []byte) (bool, []string) {
+	var badlines []string
+	warnOnly := true
+	for _, check := range consoleChecks {
+		match := check.match.FindSubmatch(consoleOutput)
+		if match != nil {
+			badline := check.desc
+			if len(match) > 1 {
+				// include first subexpression
+				badline += fmt.Sprintf(" (%s)", match[1])
+			}
+			badlines = append(badlines, badline)
+			if !check.warnOnly {
+				warnOnly = false
+			}
+		}
+	}
+	return warnOnly, badlines
+}
+
 // CheckConsole checks some console output for badness and returns short
 // descriptions of any bad lines it finds along with a boolean
 // indicating if the configuration has the bad lines marked as
@@ -1926,6 +1947,12 @@ func ScpKolet(machines []platform.Machine) error {
 func CheckConsole(output []byte, t *register.Test) (bool, []string) {
 	var badlines []string
 	warnOnly, allowRerunSuccess := true, true
+	// Check for badness using CheckConsoleText
+	addWarnOnly, addBadlines := CheckConsoleText(output)
+	if !addWarnOnly {
+		warnOnly = false
+	}
+	badlines = append(badlines, addBadlines...)
 	for _, check := range consoleChecks {
 		if check.skipFlag != nil && t != nil && t.HasFlag(*check.skipFlag) {
 			continue

mantle/platform/qemu.go

@@ -43,6 +43,7 @@ import (
 	"syscall"
 	"time"
 
+	"github.com/coreos/coreos-assembler/mantle/kola"
 	"github.com/coreos/coreos-assembler/mantle/platform/conf"
 	"github.com/coreos/coreos-assembler/mantle/util"
 	coreosarch "github.com/coreos/stream-metadata-go/arch"
@@ -255,6 +256,56 @@ func (inst *QemuInstance) WaitIgnitionError(ctx context.Context) (string, error)
 	return r.String(), nil
 }
 
+// CheckConsoleForBadness will only return if the instance
+// failed inside the CheckConsole.  The resulting string will
+// be a newline-delimited stream of JSON strings, as returned
+// by `journalctl -o json`.
+func (inst *QemuInstance) CheckConsoleForBadness(ctx context.Context) (string, error) {
+	b := bufio.NewReaderSize(inst.journalPipe, 64768)
+	var r strings.Builder
+	iscorrupted := false
+	_, err := b.Peek(1)
+	if err != nil {
+		// It's normal to get EOF if we didn't catch an error and qemu
+		// is shutting down.  We also need to handle when the Destroy()
+		// function closes the journal FD on us.
+		if e, ok := err.(*os.PathError); ok && e.Err == os.ErrClosed {
+			return "", nil
+		} else if err == io.EOF {
+			return "", nil
+		}
+		return "", errors.Wrapf(err, "Reading from journal")
+	}
+	for {
+		if err := ctx.Err(); err != nil {
+			return "", err
+		}
+
+		line, prefix, err := b.ReadLine()
+		if err != nil {
+			return r.String(), errors.Wrapf(err, "Reading from journal channel")
+		}
+		if prefix {
+			iscorrupted = true
+		}
+		if len(line) == 0 || string(line) == "{}" {
+			break
+		}
+		// Call CheckConsoleText
+		warnOnly, addBadlines := kola.CheckConsoleText(line)
+		if !warnOnly {
+			// If CheckConsoleText output contains bad lines, fail the test
+			return r.String(), fmt.Errorf("Test failed: %v", strings.Join(addBadlines, "\n"))
+		}
+		r.Write(line)
+		r.Write([]byte("\n"))
+	}
+	if iscorrupted {
+		return r.String(), fmt.Errorf("journal was truncated due to overly long line")
+	}
+	return r.String(), nil
+}
+
 // WaitAll wraps the process exit as well as WaitIgnitionError,
 // returning an error if either fail.
 func (inst *QemuInstance) WaitAll(ctx context.Context) error {
@@ -277,6 +328,18 @@ func (inst *QemuInstance) WaitAll(ctx context.Context) error {
 		}
 	}()
 
+	// Early stop due to failure in initramfs.
+	go func() {
+		buf, err := inst.CheckConsoleForBadness(waitCtx)
+		if err != nil {
+			c <- err
+			return
+		}
+		if buf != "" {
+			c <- ErrInitramfsEmergency
+			return
+		}
+	}()
 	// Machine terminated.
 	go func() {
 		select {