syz-verifier: add result processing functionality

The main utility saves reports in a file for further inspection.

2 files changed, 155 insertions, 29 deletions

diff --git a/syz-verifier/main.go b/syz-verifier/main.go
index bf24d241e..2c35e1224 100755
--- a/syz-verifier/main.go
+++ b/syz-verifier/main.go
@@ -4,9 +4,11 @@ package main
 
 import (
 	"flag"
+	"fmt"
 	"log"
 	"math/rand"
 	"net"
+	"os"
 	"path/filepath"
 	"strconv"
 	"sync"
@@ -23,6 +25,10 @@ import (
 	"github.com/google/syzkaller/vm"
 )
 
+const (
+	maxResultReports = 100
+)
+
 // Verifier TODO.
 type Verifier struct {
 	pools  map[int]*poolInfo
@@ -35,6 +41,7 @@ type Verifier struct {
 	// grouped by OS/Arch
 	workdir     string
 	crashdir    string
+	resultsdir  string
 	target      *prog.Target
 	runnerBin   string
 	executorBin string
@@ -62,7 +69,7 @@ type poolInfo struct {
 	cfg      *mgrconfig.Config
 	pool     *vm.Pool
 	Reporter report.Reporter
-	//  vmRunners keep track of what programs have been sent to each Runner.
+	//  vmRunners keeps track of what programs have been sent to each Runner.
 	//  There is one Runner executing per VM instance.
 	vmRunners map[int][]*progInfo
 	// progs stores the programs that haven't been sent to this kernel yet but
@@ -141,6 +148,9 @@ func main() {
 		osutil.MkdirAll(filepath.Join(crashdir, targetPath))
 	}
 
+	resultsdir := filepath.Join(workdir, "results")
+	osutil.MkdirAll(resultsdir)
+
 	for idx, pi := range pools {
 		var err error
 		pi.Reporter, err = report.NewReporter(pi.cfg)
@@ -159,6 +169,7 @@ func main() {
 	vrf := &Verifier{
 		workdir:     workdir,
 		crashdir:    crashdir,
+		resultsdir:  resultsdir,
 		pools:       pools,
 		target:      target,
 		choiceTable: target.BuildChoiceTable(nil, calls),
@@ -250,15 +261,11 @@ func (srv *RPCServer) NextExchange(a *rpctype.NextExchangeArgs, r *rpctype.NextE
 			Hanged: a.Hanged,
 			Info:   a.Info,
 		}
-		if srv.newResult(res, a.ProgIdx) {
-			for idx, prog := range srv.progs {
-				if a.ProgIdx == prog.idx {
-					if !verf.Verify(prog.res, prog.prog) {
-						log.Printf("mismatch found for %+v", prog.prog)
-					}
-					delete(srv.progs, idx)
-				}
-			}
+
+		prog := srv.progs[a.ProgIdx]
+		if srv.newResult(res, prog) {
+			srv.vrf.processResults(prog.res, prog.prog)
+			delete(srv.progs, a.ProgIdx)
 		}
 	}
 
@@ -267,6 +274,72 @@ func (srv *RPCServer) NextExchange(a *rpctype.NextExchangeArgs, r *rpctype.NextE
 	return nil
 }
 
+// newResult is called when a Runner sends a new Result. It returns true if all
+// Results from the corresponding programs have been received and they can be
+// sent for verification. Otherwise, it returns false.
+func (srv *RPCServer) newResult(res *verf.Result, prog *progInfo) bool {
+	prog.res = append(prog.res, res)
+	delete(prog.left, res.Pool)
+	return len(prog.left) == 0
+}
+
+// processResults will send a set of complete results for verification and, in
+// case differences are found, it will store a result report highlighting those
+// in th workdir/results directory. If writing the results fails, it returns an
+// error.
+func (vrf *Verifier) processResults(res []*verf.Result, prog *prog.Prog) {
+	rr := verf.Verify(res, prog)
+	if rr == nil {
+		return
+	}
+
+	oldest := 0
+	var oldestTime time.Time
+	for i := 0; i < maxResultReports; i++ {
+		info, err := os.Stat(filepath.Join(vrf.resultsdir, fmt.Sprintf("result-%d", i)))
+		if err != nil {
+			// There are only i-1 report files so the i-th one
+			// can be created.
+			oldest = i
+			break
+		}
+
+		// Otherwise, search for the oldest report file to
+		// overwrite as newer result reports are more useful.
+		if oldestTime.IsZero() || info.ModTime().Before(oldestTime) {
+			oldest = i
+			oldestTime = info.ModTime()
+		}
+	}
+
+	err := osutil.WriteFile(filepath.Join(vrf.resultsdir, fmt.Sprintf("result-%d", oldest)), createReport(rr))
+	if err != nil {
+		log.Printf("failed to write result-%d file, err %v", oldest, err)
+	}
+
+	log.Printf("result-%d written successfully", oldest)
+}
+
+func createReport(rr *verf.ResultReport) []byte {
+	data := fmt.Sprintf("Errno mismatches found for program:\n%s\n", rr.Prog)
+	data += "CALL REPORTS FOUND BELOW\n"
+
+	for _, cr := range rr.Reports {
+		data += fmt.Sprintf("Report for call: %s", cr.Call)
+
+		if cr.Mismatch {
+			data += " - MISMATCH FOUND"
+		}
+		data += "\n"
+		for pool, errno := range cr.Errnos {
+			data += fmt.Sprintf("Pool: %d, Errno: %d, Flag: %d\n", pool, errno, cr.Flags[pool])
+		}
+		data += "\n"
+	}
+
+	return []byte(data)
+}
+
 // newProgram returns a new program for the Runner identified by poolIdx and
 // vmIdx and the program's index.
 func (srv *RPCServer) newProgram(poolIdx, vmIdx int) ([]byte, int) {
@@ -298,20 +371,6 @@ func (vrf *Verifier) generate() (*prog.Prog, int) {
 	return vrf.target.Generate(vrf.rnd, prog.RecommendedCalls, vrf.choiceTable), vrf.progIdx
 }
 
-// newResult is called when a Runner sends a new Result. It returns true if all
-// Results from the corresponding programs have been received and they can be
-// sent for verification. Otherwise, it returns false.
-func (srv *RPCServer) newResult(res *verf.Result, idx int) bool {
-	for _, prog := range srv.progs {
-		if prog.idx == idx {
-			prog.res = append(prog.res, res)
-			delete(prog.left, res.Pool)
-			return len(prog.left) == 0
-		}
-	}
-	return false
-}
-
 // cleanup is called when a vm.Instance crashes.
 func (srv *RPCServer) cleanup(poolIdx, vmIdx int) {
 	srv.mu.Lock()
@@ -321,9 +380,7 @@ func (srv *RPCServer) cleanup(poolIdx, vmIdx int) {
 	for idx, prog := range progs {
 		delete(prog.left, poolIdx)
 		if len(prog.left) == 0 {
-			if !verf.Verify(prog.res, prog.prog) {
-				log.Printf("mismatch found for %+v", prog.prog)
-			}
+			srv.vrf.processResults(prog.res, prog.prog)
 			delete(srv.progs, idx)
 			continue
 		}
diff --git a/syz-verifier/main_test.go b/syz-verifier/main_test.go
index 51437b148..d17e56a40 100644
--- a/syz-verifier/main_test.go
+++ b/syz-verifier/main_test.go
@@ -3,11 +3,16 @@
 package main
 
 import (
+	"log"
 	"math/rand"
+	"os"
+	"path/filepath"
 	"testing"
 	"time"
 
 	"github.com/google/go-cmp/cmp"
+	"github.com/google/syzkaller/pkg/ipc"
+	"github.com/google/syzkaller/pkg/osutil"
 	"github.com/google/syzkaller/pkg/rpctype"
 	"github.com/google/syzkaller/prog"
 	"github.com/google/syzkaller/syz-verifier/verf"
@@ -123,7 +128,7 @@ func TestNewResult(t *testing.T) {
 	for _, test := range tests {
 		t.Run(test.name, func(t *testing.T) {
 			setup(t)
-			gotReady := srv.newResult(&test.res, test.idx)
+			gotReady := srv.newResult(&test.res, srv.progs[test.idx])
 			if test.wantReady != gotReady {
 				t.Errorf("srv.newResult: got %v want %v", gotReady, test.wantReady)
 			}
@@ -152,4 +157,68 @@ func TestConnect(t *testing.T) {
 	}
 }
 
-// TODO: add integration tests for NewExchange and cleanup.
+func makeResult(pool int, errnos []int) *verf.Result {
+	r := &verf.Result{Pool: pool, Info: ipc.ProgInfo{Calls: []ipc.CallInfo{}}}
+	for _, e := range errnos {
+		r.Info.Calls = append(r.Info.Calls, ipc.CallInfo{Errno: e})
+	}
+	return r
+}
+
+func TestProcessResults(t *testing.T) {
+	p := "breaks_returns()\n" +
+		"minimize$0(0x1, 0x1)\n" +
+		"test$res0()\n"
+	tests := []struct {
+		name       string
+		res        []*verf.Result
+		prog       string
+		wantExist  bool
+		wantResIdx int
+	}{
+		{
+			name: "report written",
+			res: []*verf.Result{
+				makeResult(1, []int{1, 3, 2}),
+				makeResult(4, []int{1, 3, 5}),
+			},
+			wantExist: true,
+		},
+		{
+			name: "no report written",
+			res: []*verf.Result{
+				makeResult(2, []int{11, 33, 22}),
+				makeResult(3, []int{11, 33, 22}),
+			},
+		},
+	}
+	for _, test := range tests {
+		t.Run(test.name, func(t *testing.T) {
+			target := prog.InitTargetTest(t, "test", "64")
+			prog, err := target.Deserialize([]byte(p), prog.Strict)
+			if err != nil {
+				t.Fatalf("failed to deserialise test program: %v", err)
+			}
+
+			resultsdir := "test"
+			err = osutil.MkdirAll(resultsdir)
+			if err != nil {
+				t.Fatalf("failed to create results directory: %v", err)
+			}
+			vrf := Verifier{}
+			vrf.resultsdir, err = filepath.Abs(resultsdir)
+			if err != nil {
+				t.Fatalf("failed to get absolute path of resultsdir: %v", err)
+			}
+			resultFile := filepath.Join(vrf.resultsdir, "result-3")
+
+			vrf.processResults(test.res, prog)
+
+			if got, want := osutil.IsExist(resultFile), test.wantExist; got != want {
+				log.Printf("%v", test.wantExist)
+				t.Errorf("osutil.IsExist report file: got %v want %v", got, want)
+			}
+			os.Remove(filepath.Join(vrf.resultsdir, "result-3"))
+		})
+	}
+}