syz-verifier: report the number of programs executed per minute

4 files changed, 19 insertions, 4 deletions

diff --git a/syz-verifier/main.go b/syz-verifier/main.go
index ca712b7df..eb20d44e1 100755
--- a/syz-verifier/main.go
+++ b/syz-verifier/main.go
@@ -411,6 +411,7 @@ func (srv *RPCServer) newResult(res *verf.Result, prog *progInfo) bool {
 // in th workdir/results directory. If writing the results fails, it returns an
 // error.
 func (vrf *Verifier) processResults(res []*verf.Result, prog *prog.Prog) {
+	vrf.stats.Progs++
 	rr := verf.Verify(res, prog, vrf.stats)
 	if rr == nil {
 		return
diff --git a/syz-verifier/main_test.go b/syz-verifier/main_test.go
index 84574b452..4a7eb9bbf 100644
--- a/syz-verifier/main_test.go
+++ b/syz-verifier/main_test.go
@@ -417,6 +417,7 @@ func TestProcessResults(t *testing.T) {
 			wantExist: true,
 			wantStats: &stats.Stats{
 				TotalMismatches: 1,
+				Progs:           1,
 				Calls: map[string]*stats.CallStats{
 					"breaks_returns": makeCallStats("breaks_returns", 1, 0, map[int]bool{}),
 					"test$res0":      makeCallStats("test$res0", 1, 1, map[int]bool{2: true, 5: true}),
@@ -431,6 +432,7 @@ func TestProcessResults(t *testing.T) {
 				makeResult(3, []int{11, 33, 22}),
 			},
 			wantStats: &stats.Stats{
+				Progs: 1,
 				Calls: map[string]*stats.CallStats{
 					"breaks_returns": makeCallStats("breaks_returns", 1, 0, map[int]bool{}),
 					"minimize$0":     makeCallStats("minimize$0", 1, 0, map[int]bool{}),
@@ -529,6 +531,7 @@ func TestCleanup(t *testing.T) {
 					},
 				}},
 			wantStats: &stats.Stats{
+				Progs: 1,
 				Calls: map[string]*stats.CallStats{
 					"breaks_returns": makeCallStats("breaks_returns", 1, 0, map[int]bool{}),
 					"minimize$0":     makeCallStats("minimize$0", 1, 0, map[int]bool{}),
@@ -551,6 +554,7 @@ func TestCleanup(t *testing.T) {
 				}},
 			wantStats: &stats.Stats{
 				TotalMismatches: 1,
+				Progs:           1,
 				Calls: map[string]*stats.CallStats{
 					"breaks_returns": makeCallStats("breaks_returns", 1, 0, map[int]bool{}),
 					"minimize$0":     makeCallStats("minimize$0", 1, 0, map[int]bool{}),
diff --git a/syz-verifier/stats/stats.go b/syz-verifier/stats/stats.go
index 440a9535d..9932ed517 100644
--- a/syz-verifier/stats/stats.go
+++ b/syz-verifier/stats/stats.go
@@ -11,6 +11,7 @@ import (
 	"os"
 	"os/signal"
 	"sort"
+	"time"
 
 	"github.com/google/syzkaller/prog"
 )
@@ -21,6 +22,8 @@ type Stats struct {
 	// Calls stores statistics for all supported system calls.
 	Calls           map[string]*CallStats
 	TotalMismatches int
+	Progs           int
+	StartTime       time.Time
 }
 
 // CallStats stores information used to generate statistics for the
@@ -41,7 +44,10 @@ type CallStats struct {
 // InitStats creates a stats object that will report verification
 // statistics when an os.Interrupt occurs.
 func InitStats(calls map[*prog.Syscall]bool, w io.Writer) *Stats {
-	s := &Stats{Calls: make(map[string]*CallStats)}
+	s := &Stats{
+		Calls:     make(map[string]*CallStats),
+		StartTime: time.Now(),
+	}
 	for c := range calls {
 		s.Calls[c.Name] = &CallStats{Name: c.Name, States: make(map[int]bool)}
 	}
@@ -50,11 +56,12 @@ func InitStats(calls map[*prog.Syscall]bool, w io.Writer) *Stats {
 	signal.Notify(c, os.Interrupt)
 	go func() {
 		<-c
+		dt := time.Since(s.StartTime).Minutes()
 		if s.TotalMismatches < 0 {
 			fmt.Fprint(w, "No mismatches occurred until syz-verifier was stopped.")
 			os.Exit(0)
 		}
-		s.ReportGlobalStats(w)
+		s.ReportGlobalStats(w, dt)
 		os.Exit(0)
 	}()
 
@@ -85,10 +92,11 @@ func getPercentage(value, total int) float64 {
 // ReportGlobalStats creates a report with statistics about all the
 // supported system calls for which errno mismatches were identified in
 // the verified programs, shown in decreasing order.
-func (s *Stats) ReportGlobalStats(w io.Writer) {
+func (s *Stats) ReportGlobalStats(w io.Writer, deltaTime float64) {
 	tc := s.totalCallsExecuted()
 	fmt.Fprintf(w, "total number of mismatches / total number of calls "+
 		"executed: %d / %d (%0.2f %%)\n\n", s.TotalMismatches, tc, getPercentage(s.TotalMismatches, tc))
+	fmt.Fprintf(w, "programs / minute: %0.2f\n\n", float64(s.Progs)/deltaTime)
 	cs := s.getOrderedStats()
 	for _, c := range cs {
 		fmt.Fprintf(w, "%s\n", s.ReportCallStats(c.Name))
diff --git a/syz-verifier/stats/stats_test.go b/syz-verifier/stats/stats_test.go
index e82fd5d4c..1ced8c1b1 100644
--- a/syz-verifier/stats/stats_test.go
+++ b/syz-verifier/stats/stats_test.go
@@ -12,6 +12,7 @@ import (
 
 func getTestStats() *Stats {
 	return &Stats{
+		Progs:           24,
 		TotalMismatches: 10,
 		Calls: map[string]*CallStats{
 			"foo": {"foo", 2, 8, map[int]bool{11: true, 3: true}},
@@ -55,10 +56,11 @@ func TestReportCallStats(t *testing.T) {
 func TestReportGlobalStats(t *testing.T) {
 	s := getTestStats()
 	out := bytes.Buffer{}
-	s.ReportGlobalStats(&out)
+	s.ReportGlobalStats(&out, float64(10))
 	got, want := out.String(),
 		"total number of mismatches / total number of calls "+
 			"executed: 10 / 20 (50.00 %)\n\n"+
+			"programs / minute: 2.40\n\n"+
 			"statistics for bar:\n"+
 			"\t↳ mismatches of bar / occurrences of bar: 5 / 6 (83.33 %)\n"+
 			"\t↳ mismatches of bar / total number of mismatches: 5 / 10 (50.00 %)\n"+