diff --git a/pkg/build/netbsd.go b/pkg/build/netbsd.go index 21564e1aa7db..199ebc424b1b 100644 --- a/pkg/build/netbsd.go +++ b/pkg/build/netbsd.go @@ -158,13 +158,13 @@ func (ctx netbsd) copyKernelToDisk(targetArch, vmType, outputDir, kernel string) commands = append(commands, "sync") // Run sync so that the copied image is stored properly. ctxTimeout, cancel := context.WithTimeout(context.Background(), time.Minute) defer cancel() - _, rep, err := inst.Run(ctxTimeout, reporter, strings.Join(commands, ";")) + _, reps, err := inst.Run(ctxTimeout, reporter, strings.Join(commands, ";")) if err != nil { return fmt.Errorf("error syncing the instance %w", err) } // Make sure that the command has executed properly. - if rep != nil { - return fmt.Errorf("error executing sync: %v", rep.Title) + if len(reps) > 0 { + return fmt.Errorf("error executing sync: %v", reps[0].Title) } return nil } diff --git a/pkg/html/pages/style.css b/pkg/html/pages/style.css index 5da7359e608b..aecc40b7e017 100644 --- a/pkg/html/pages/style.css +++ b/pkg/html/pages/style.css @@ -177,6 +177,12 @@ table td, table th { text-align: right; } +.list_table .rank { + width: 55pt; + font-family: monospace; + text-align: right; +} + .list_table .discussions { font-family: monospace; text-align: left; @@ -493,3 +499,19 @@ aside { /* Change the background color of the dropdown button when the dropdown content is shown */ .dropdown:hover .dropbtn {background-color: #ddd;} + +.rank .tooltiptext { + visibility: hidden; + background-color: black; + color: #fff; + text-align: left; + border-radius: 6px; + padding: 5px 0; + + /* Position the tooltip */ + position: absolute; + z-index: 1; +} +.rank:hover .tooltiptext { + visibility: visible; +} \ No newline at end of file diff --git a/pkg/instance/execprog.go b/pkg/instance/execprog.go index 0b9f9ebf79c8..7c97819f4fed 100644 --- a/pkg/instance/execprog.go +++ b/pkg/instance/execprog.go @@ -126,10 +126,14 @@ func (inst *ExecProgInstance) runCommand(command string, duration time.Duration, } ctxTimeout, cancel := context.WithTimeout(context.Background(), duration) defer cancel() - output, rep, err := inst.VMInstance.Run(ctxTimeout, inst.reporter, command, + output, reps, err := inst.VMInstance.Run(ctxTimeout, inst.reporter, command, vm.WithExitCondition(exitCondition), optionalBeforeContext, ) + var rep *report.Report + if len(reps) > 0 { + rep = reps[0] + } if err != nil { return nil, fmt.Errorf("failed to run command in VM: %w", err) } diff --git a/pkg/manager/crash.go b/pkg/manager/crash.go index 44df6e63e017..a62ec8280125 100644 --- a/pkg/manager/crash.go +++ b/pkg/manager/crash.go @@ -17,6 +17,7 @@ import ( "github.com/google/syzkaller/pkg/log" "github.com/google/syzkaller/pkg/mgrconfig" "github.com/google/syzkaller/pkg/osutil" + "github.com/google/syzkaller/pkg/report" "github.com/google/syzkaller/prog" ) @@ -85,10 +86,14 @@ func (cs *CrashStore) SaveCrash(crash *Crash) (bool, error) { } osutil.WriteFile(filename, data) } + reps := append([]*report.Report{crash.Report}, crash.TailReports...) writeOrRemove("log", crash.Output) writeOrRemove("tag", []byte(cs.Tag)) - writeOrRemove("report", crash.Report.Report) + writeOrRemove("report", report.MergeReportBytes(reps)) writeOrRemove("machineInfo", crash.MachineInfo) + if err := report.AddTitleStat(filepath.Join(dir, "title-stat"), reps); err != nil { + return false, fmt.Errorf("report.AddTitleStat: %w", err) + } return first, nil } @@ -211,6 +216,7 @@ type CrashInfo struct { type BugInfo struct { ID string Title string + TailTitles []*report.TitleFreqRank FirstTime time.Time LastTime time.Time HasRepro bool @@ -218,6 +224,7 @@ type BugInfo struct { StraceFile string // relative to the workdir ReproAttempts int Crashes []*CrashInfo + Rank int } func (cs *CrashStore) BugInfo(id string, full bool) (*BugInfo, error) { @@ -233,6 +240,16 @@ func (cs *CrashStore) BugInfo(id string, full bool) (*BugInfo, error) { return nil, err } ret.Title = strings.TrimSpace(string(desc)) + + // Bug rank may go up over time if we observe higher ranked bugs as a consequence of the first failure. + ret.Rank = report.TitlesToImpact(ret.Title) + if titleStat, err := report.ReadStatFile(filepath.Join(dir, "title-stat")); err == nil { + ret.TailTitles = report.ExplainTitleStat(titleStat) + for _, ti := range ret.TailTitles { + ret.Rank = max(ret.Rank, ti.Rank) + } + } + ret.FirstTime = osutil.CreationTime(stat) ret.LastTime = stat.ModTime() files, err := osutil.ListDir(dir) diff --git a/pkg/manager/diff.go b/pkg/manager/diff.go index 57340314edfd..8b57e580708f 100644 --- a/pkg/manager/diff.go +++ b/pkg/manager/diff.go @@ -675,7 +675,7 @@ func (kc *kernelContext) runInstance(ctx context.Context, inst *vm.Instance, cmd := fmt.Sprintf("%v runner %v %v %v", executorBin, inst.Index(), host, port) ctxTimeout, cancel := context.WithTimeout(ctx, kc.cfg.Timeouts.VMRunningTime) defer cancel() - _, rep, err := inst.Run(ctxTimeout, kc.reporter, cmd, + _, reps, err := inst.Run(ctxTimeout, kc.reporter, cmd, vm.WithExitCondition(vm.ExitTimeout), vm.WithInjectExecuting(injectExec), vm.WithEarlyFinishCb(func() { @@ -685,7 +685,10 @@ func (kc *kernelContext) runInstance(ctx context.Context, inst *vm.Instance, kc.serv.StopFuzzing(inst.Index()) }), ) - return rep, err + if len(reps) > 0 { + return reps[0], err + } + return nil, err } func (kc *kernelContext) triageProgress() float64 { diff --git a/pkg/manager/html/main.html b/pkg/manager/html/main.html index 42e92ac2bc93..43652cbf6d62 100644 --- a/pkg/manager/html/main.html +++ b/pkg/manager/html/main.html @@ -26,6 +26,7 @@ Description + Rank Count First Time Last Time @@ -37,6 +38,14 @@ {{range $c := $.Crashes}} {{$c.Title}} + + {{if $c.RankTooltip}} + {{$c.Rank}} +
{{$c.RankTooltip}}
+ {{else}} + {{$c.Rank}} + {{end}} + {{len $c.Crashes}} {{formatTime $c.FirstTime}} {{formatTime $c.LastTime}} diff --git a/pkg/manager/http.go b/pkg/manager/http.go index e6a7d6b46c51..61d208f410cc 100644 --- a/pkg/manager/http.go +++ b/pkg/manager/http.go @@ -29,6 +29,7 @@ import ( "github.com/google/syzkaller/pkg/html/pages" "github.com/google/syzkaller/pkg/log" "github.com/google/syzkaller/pkg/mgrconfig" + "github.com/google/syzkaller/pkg/report" "github.com/google/syzkaller/pkg/stat" "github.com/google/syzkaller/pkg/vcs" "github.com/google/syzkaller/pkg/vminfo" @@ -355,12 +356,33 @@ func makeUICrashType(info *BugInfo, startTime time.Time, repros map[string]bool) triaged := reproStatus(info.HasRepro, info.HasCRepro, repros[info.Title], info.ReproAttempts >= MaxReproAttempts) return UICrashType{ - BugInfo: *info, - New: info.FirstTime.After(startTime), - Active: info.LastTime.After(startTime), - Triaged: triaged, - Crashes: crashes, + BugInfo: *info, + RankTooltip: higherRankTooltip(info.Title, info.TailTitles), + New: info.FirstTime.After(startTime), + Active: info.LastTime.After(startTime), + Triaged: triaged, + Crashes: crashes, + } +} + +// higherRankTooltip generates the prioritized list of the titles with higher Rank +// than the firstTitle has. +func higherRankTooltip(firstTitle string, titlesInfo []*report.TitleFreqRank) string { + baseRank := report.TitlesToImpact(firstTitle) + res := "" + for _, ti := range titlesInfo { + if ti.Rank <= baseRank { + continue + } + res += fmt.Sprintf("[rank %2v, freq %5.1f%%] %s\n", + ti.Rank, + 100*float32(ti.Count)/float32(ti.Total), + ti.Title) + } + if res != "" { + return fmt.Sprintf("[rank %2v, originally] %s\n%s", baseRank, firstTitle, res) } + return res } var crashIDRe = regexp.MustCompile(`^\w+$`) @@ -1024,10 +1046,11 @@ type UICrashPage struct { type UICrashType struct { BugInfo - New bool // was first found in the current run - Active bool // was found in the current run - Triaged string - Crashes []UICrash + RankTooltip string + New bool // was first found in the current run + Active bool // was found in the current run + Triaged string + Crashes []UICrash } type UICrash struct { diff --git a/pkg/manager/repro.go b/pkg/manager/repro.go index e7034b1863d5..184945c5ce9b 100644 --- a/pkg/manager/repro.go +++ b/pkg/manager/repro.go @@ -31,6 +31,7 @@ type Crash struct { Manual bool FullRepro bool // used by the diff fuzzer to do a full scale reproduction *report.Report + TailReports []*report.Report } func (c *Crash) FullTitle() string { diff --git a/pkg/report/impact_score.go b/pkg/report/impact_score.go index 63adb652ad41..8139644d2a6a 100644 --- a/pkg/report/impact_score.go +++ b/pkg/report/impact_score.go @@ -4,6 +4,8 @@ package report import ( + "sort" + "github.com/google/syzkaller/pkg/report/crash" ) @@ -62,3 +64,45 @@ func TitlesToImpact(title string, otherTitles ...string) int { } return maxImpact } + +type TitleFreqRank struct { + Title string + Count int + Total int + Rank int +} + +func ExplainTitleStat(ts *titleStat) []*TitleFreqRank { + titleCount := map[string]int{} + var totalCount int + ts.visit(func(count int, titles ...string) { + uniq := map[string]bool{} + for _, title := range titles { + uniq[title] = true + } + for title := range uniq { + titleCount[title] += count + } + totalCount += count + }) + var res []*TitleFreqRank + for title, count := range titleCount { + res = append(res, &TitleFreqRank{ + Title: title, + Count: count, + Total: totalCount, + Rank: TitlesToImpact(title), + }) + } + sort.Slice(res, func(l, r int) bool { + if res[l].Rank != res[r].Rank { + return res[l].Rank > res[r].Rank + } + lTitle, rTitle := res[l].Title, res[r].Title + if titleCount[lTitle] != titleCount[rTitle] { + return titleCount[lTitle] > titleCount[rTitle] + } + return lTitle < rTitle + }) + return res +} diff --git a/pkg/report/report.go b/pkg/report/report.go index 088f8c08910b..b4f93e3ac0bd 100644 --- a/pkg/report/report.go +++ b/pkg/report/report.go @@ -943,3 +943,18 @@ func TitleToCrashType(title string) crash.Type { } return crash.UnknownType } + +const reportSeparator = "\n<<<<<<<<<<<<<<< tail report >>>>>>>>>>>>>>>\n\n" + +func MergeReportBytes(reps []*Report) []byte { + var res []byte + for _, rep := range reps { + res = append(res, rep.Report...) + res = append(res, []byte(reportSeparator)...) + } + return res +} + +func SplitReportBytes(data []byte) [][]byte { + return bytes.Split(data, []byte(reportSeparator)) +} diff --git a/pkg/report/report_test.go b/pkg/report/report_test.go index 2184cd411308..8c863fe8daff 100644 --- a/pkg/report/report_test.go +++ b/pkg/report/report_test.go @@ -510,3 +510,38 @@ BCDEF`), Truncate([]byte(`0123456789ABCDEF`), 0, 5)) DEF`), Truncate([]byte(`0123456789ABCDEF`), 4, 3)) } + +func TestSplitReportBytes(t *testing.T) { + tests := []struct { + name string + input []byte + wantFirst string + }{ + { + name: "empty", + input: nil, + wantFirst: "", + }, + { + name: "single", + input: []byte("report1"), + wantFirst: "report1", + }, + { + name: "split in the middle", + input: []byte("report1" + reportSeparator + "report2"), + wantFirst: "report1", + }, + { + name: "split in the middle, save new line", + input: []byte("report1\n" + reportSeparator + "report2"), + wantFirst: "report1\n", + }, + } + for _, test := range tests { + t.Run(test.name, func(t *testing.T) { + splitted := SplitReportBytes(test.input) + assert.Equal(t, test.wantFirst, string(splitted[0])) + }) + } +} diff --git a/pkg/report/title_stat.go b/pkg/report/title_stat.go new file mode 100644 index 000000000000..5b3cd3fb791c --- /dev/null +++ b/pkg/report/title_stat.go @@ -0,0 +1,88 @@ +// Copyright 2025 syzkaller project authors. All rights reserved. +// Use of this source code is governed by Apache 2 LICENSE that can be found in the LICENSE file. + +package report + +import ( + "encoding/json" + "errors" + "fmt" + "maps" + "os" +) + +func AddTitleStat(file string, reps []*Report) error { + var titles []string + for _, rep := range reps { + titles = append(titles, rep.Title) + } + stat, err := ReadStatFile(file) + if err != nil { + return fmt.Errorf("report.ReadStatFile: %w", err) + } + stat.add(titles) + if err := writeStatFile(file, stat); err != nil { + return fmt.Errorf("writeStatFile: %w", err) + } + return nil +} + +func ReadStatFile(file string) (*titleStat, error) { + stat := &titleStat{} + if _, err := os.Stat(file); errors.Is(err, os.ErrNotExist) { + return stat, nil + } + data, err := os.ReadFile(file) + if err != nil { + return nil, err + } + if len(data) == 0 { + return stat, nil + } + if err := json.Unmarshal(data, stat); err != nil { + return nil, err + } + return stat, nil +} + +func writeStatFile(file string, stat *titleStat) error { + data, err := json.MarshalIndent(stat, "", "\t") + if err != nil { + return err + } + if err := os.WriteFile(file, data, 0644); err != nil { + return err + } + return nil +} + +type titleStatNodes map[string]*titleStat + +type titleStat struct { + Count int + Nodes titleStatNodes +} + +func (ts *titleStat) add(reps []string) { + if len(reps) == 0 { + return + } + if ts.Nodes == nil { + ts.Nodes = make(titleStatNodes) + } + if ts.Nodes[reps[0]] == nil { + ts.Nodes[reps[0]] = &titleStat{} + } + ts.Nodes[reps[0]].Count++ + ts.Nodes[reps[0]].add(reps[1:]) +} + +func (ts *titleStat) visit(cb func(int, ...string), titles ...string) { + if len(ts.Nodes) == 0 { + cb(ts.Count, titles...) + return + } + for title := range maps.Keys(ts.Nodes) { + ts.Nodes[title].visit(cb, append(titles, title)...) + } +} diff --git a/pkg/report/title_stat_test.go b/pkg/report/title_stat_test.go new file mode 100644 index 000000000000..216af456ca99 --- /dev/null +++ b/pkg/report/title_stat_test.go @@ -0,0 +1,76 @@ +// Copyright 2025 syzkaller project authors. All rights reserved. +// Use of this source code is governed by Apache 2 LICENSE that can be found in the LICENSE file. + +package report + +import ( + "os" + "testing" + + "github.com/stretchr/testify/assert" +) + +func TestAddTitleStat(t *testing.T) { + tests := []struct { + name string + base string + reps [][]*Report + want *titleStat + }{ + { + name: "read empty", + want: &titleStat{}, + }, + { + name: "add single", + reps: [][]*Report{{{Title: "warning 1"}}}, + want: &titleStat{ + Nodes: titleStatNodes{ + "warning 1": {Count: 1}, + }, + }, + }, + { + name: "add chain", + reps: [][]*Report{{{Title: "warning 1"}, {Title: "warning 2"}}}, + want: &titleStat{ + Nodes: titleStatNodes{ + "warning 1": {Count: 1, + Nodes: titleStatNodes{ + "warning 2": {Count: 1}, + }, + }, + }, + }, + }, + { + name: "add multi chains", + reps: [][]*Report{{{Title: "warning 1"}, {Title: "warning 2"}}, {{Title: "warning 1"}, {Title: "warning 3"}}}, + want: &titleStat{ + Nodes: titleStatNodes{ + "warning 1": {Count: 2, + Nodes: titleStatNodes{ + "warning 2": {Count: 1}, + "warning 3": {Count: 1}, + }, + }, + }, + }, + }, + } + for _, test := range tests { + t.Run(test.name, func(t *testing.T) { + t.Parallel() + tmpFile := t.TempDir() + "/test.input" + err := os.WriteFile(tmpFile, []byte(test.base), 0644) + assert.NoError(t, err) + for _, reps := range test.reps { + err = AddTitleStat(tmpFile, reps) + assert.NoError(t, err) + } + got, err := ReadStatFile(tmpFile) + assert.NoError(t, err) + assert.Equal(t, test.want, got) + }) + } +} diff --git a/syz-manager/manager.go b/syz-manager/manager.go index 177cd5f01ad0..3f94bd23a714 100644 --- a/syz-manager/manager.go +++ b/syz-manager/manager.go @@ -597,7 +597,7 @@ func (mgr *Manager) fuzzerInstance(ctx context.Context, inst *vm.Instance, updIn injectExec := make(chan bool, 10) serv.CreateInstance(inst.Index(), injectExec, updInfo) - rep, vmInfo, err := mgr.runInstanceInner(ctx, inst, + reps, vmInfo, err := mgr.runInstanceInner(ctx, inst, vm.WithExitCondition(vm.ExitTimeout), vm.WithInjectExecuting(injectExec), vm.WithEarlyFinishCb(func() { @@ -607,6 +607,10 @@ func (mgr *Manager) fuzzerInstance(ctx context.Context, inst *vm.Instance, updIn serv.StopFuzzing(inst.Index()) })) var extraExecs []report.ExecutorInfo + var rep *report.Report + if len(reps) != 0 { + rep = reps[0] + } if rep != nil && rep.Executor != nil { extraExecs = []report.ExecutorInfo{*rep.Executor} } @@ -622,6 +626,7 @@ func (mgr *Manager) fuzzerInstance(ctx context.Context, inst *vm.Instance, updIn mgr.crashes <- &manager.Crash{ InstanceIndex: inst.Index(), Report: rep, + TailReports: reps[1:], } } if err != nil { @@ -630,7 +635,7 @@ func (mgr *Manager) fuzzerInstance(ctx context.Context, inst *vm.Instance, updIn } func (mgr *Manager) runInstanceInner(ctx context.Context, inst *vm.Instance, opts ...func(*vm.RunOptions), -) (*report.Report, []byte, error) { +) ([]*report.Report, []byte, error) { fwdAddr, err := inst.Forward(mgr.serv.Port()) if err != nil { return nil, nil, fmt.Errorf("failed to setup port forwarding: %w", err) @@ -656,11 +661,11 @@ func (mgr *Manager) runInstanceInner(ctx context.Context, inst *vm.Instance, opt cmd := fmt.Sprintf("%v runner %v %v %v", executorBin, inst.Index(), host, port) ctxTimeout, cancel := context.WithTimeout(ctx, mgr.cfg.Timeouts.VMRunningTime) defer cancel() - _, rep, err := inst.Run(ctxTimeout, mgr.reporter, cmd, opts...) + _, reps, err := inst.Run(ctxTimeout, mgr.reporter, cmd, opts...) if err != nil { return nil, nil, fmt.Errorf("failed to run fuzzer: %w", err) } - if rep == nil { + if len(reps) == 0 { // This is the only "OK" outcome. log.Logf(0, "VM %v: running for %v, restarting", inst.Index(), time.Since(start)) return nil, nil, nil @@ -669,7 +674,7 @@ func (mgr *Manager) runInstanceInner(ctx context.Context, inst *vm.Instance, opt if err != nil { vmInfo = []byte(fmt.Sprintf("error getting VM info: %v\n", err)) } - return rep, vmInfo, nil + return reps, vmInfo, nil } func (mgr *Manager) emailCrash(crash *manager.Crash) { @@ -708,7 +713,10 @@ func (mgr *Manager) saveCrash(crash *manager.Crash) bool { if crash.Suppressed { flags += " [suppressed]" } - log.Logf(0, "VM %v: crash: %v%v", crash.InstanceIndex, crash.Title, flags) + log.Logf(0, "VM %v: crash: %v%v", crash.InstanceIndex, crash.Report.Title, flags) + for i, report := range crash.TailReports { + log.Logf(0, "VM %v: crash(tail%d): %v%v", crash.InstanceIndex, i, report.Title, flags) + } if mgr.mode.FailOnCrashes { path := filepath.Join(mgr.cfg.Workdir, "report.json") @@ -745,7 +753,7 @@ func (mgr *Manager) saveCrash(crash *manager.Crash) bool { Suppressed: crash.Suppressed, Recipients: crash.Recipients.ToDash(), Log: crash.Output, - Report: crash.Report.Report, + Report: report.SplitReportBytes(crash.Report.Report)[0], MachineInfo: crash.MachineInfo, } setGuiltyFiles(dc, crash.Report) @@ -877,27 +885,27 @@ func (mgr *Manager) saveRepro(res *manager.ReproResult) { // so maybe corrupted report detection is broken. // 3. Reproduction is expensive so it's good to persist the result. - report := repro.Report - output := report.Output + reproReport := repro.Report + output := reproReport.Output var crashFlags dashapi.CrashFlags if res.Strace != nil { // If syzkaller managed to successfully run the repro with strace, send // the report and the output generated under strace. - report = res.Strace.Report + reproReport = res.Strace.Report output = res.Strace.Output crashFlags = dashapi.CrashUnderStrace } dc := &dashapi.Crash{ BuildID: mgr.cfg.Tag, - Title: report.Title, - AltTitles: report.AltTitles, - Suppressed: report.Suppressed, - Recipients: report.Recipients.ToDash(), + Title: reproReport.Title, + AltTitles: reproReport.AltTitles, + Suppressed: reproReport.Suppressed, + Recipients: reproReport.Recipients.ToDash(), Log: output, Flags: crashFlags, - Report: report.Report, + Report: report.SplitReportBytes(reproReport.Report)[0], ReproOpts: repro.Opts.Serialize(), ReproSyz: progText, ReproC: cprogText, @@ -905,7 +913,7 @@ func (mgr *Manager) saveRepro(res *manager.ReproResult) { Assets: mgr.uploadReproAssets(repro), OriginalTitle: res.Crash.Title, } - setGuiltyFiles(dc, report) + setGuiltyFiles(dc, reproReport) if _, err := mgr.dash.ReportCrash(dc); err != nil { log.Logf(0, "failed to report repro to dashboard: %v", err) } else { diff --git a/vm/vm.go b/vm/vm.go index 3aa86d6b610b..e155fd8e5c44 100644 --- a/vm/vm.go +++ b/vm/vm.go @@ -294,7 +294,7 @@ func WithEarlyFinishCb(cb func()) func(*RunOptions) { // and the kernel console output. It detects kernel oopses in output, lost connections, hangs, etc. // Returns command+kernel output and a non-symbolized crash report (nil if no error happens). func (inst *Instance) Run(ctx context.Context, reporter *report.Reporter, command string, opts ...func(*RunOptions)) ( - []byte, *report.Report, error) { + []byte, []*report.Report, error) { runOptions := &RunOptions{ beforeContext: 128 << 10, afterContext: 128 << 10, @@ -316,8 +316,8 @@ func (inst *Instance) Run(ctx context.Context, reporter *report.Reporter, comman reporter: reporter, lastExecuteTime: time.Now(), } - rep := mon.monitorExecution() - return mon.output, rep, nil + reps := mon.monitorExecution() + return mon.output, reps, nil } func (inst *Instance) Info() ([]byte, error) { @@ -327,11 +327,11 @@ func (inst *Instance) Info() ([]byte, error) { return nil, nil } -func (inst *Instance) diagnose(rep *report.Report) ([]byte, bool) { - if rep == nil { - panic("rep is nil") +func (inst *Instance) diagnose(reps []*report.Report) ([]byte, bool) { + if len(reps) == 0 { + panic("reps is empty") } - return inst.impl.Diagnose(rep) + return inst.impl.Diagnose(reps[0]) } func (inst *Instance) Index() int { @@ -368,7 +368,7 @@ type monitor struct { extractCalled bool } -func (mon *monitor) monitorExecution() *report.Report { +func (mon *monitor) monitorExecution() []*report.Report { ticker := time.NewTicker(mon.tickerPeriod * mon.inst.pool.timeouts.Scale) defer ticker.Stop() defer func() { @@ -387,10 +387,10 @@ func (mon *monitor) monitorExecution() *report.Report { if mon.exitCondition&ExitNormal == 0 { crash = lostConnectionCrash } - return mon.extractError(crash) + return mon.extractErrors(crash) case ErrTimeout: if mon.exitCondition&ExitTimeout == 0 { - return mon.extractError(timeoutCrash) + return mon.extractErrors(timeoutCrash) } return nil default: @@ -400,7 +400,7 @@ func (mon *monitor) monitorExecution() *report.Report { if mon.exitCondition&ExitError == 0 { crash = lostConnectionCrash } - return mon.extractError(crash) + return mon.extractErrors(crash) } case out, ok := <-mon.outc: if !ok { @@ -417,7 +417,7 @@ func (mon *monitor) monitorExecution() *report.Report { // Detect both "no output whatsoever" and "kernel episodically prints // something to console, but fuzzer is not actually executing programs". if time.Since(mon.lastExecuteTime) > mon.inst.pool.timeouts.NoOutput { - return mon.extractError(noOutputCrash) + return mon.extractErrors(noOutputCrash) } case <-Shutdown: return nil @@ -425,14 +425,14 @@ func (mon *monitor) monitorExecution() *report.Report { } } -func (mon *monitor) appendOutput(out []byte) (*report.Report, bool) { +func (mon *monitor) appendOutput(out []byte) ([]*report.Report, bool) { lastPos := len(mon.output) mon.output = append(mon.output, out...) if bytes.Contains(mon.output[lastPos:], []byte(executedProgramsStart)) { mon.lastExecuteTime = time.Now() } if mon.reporter.ContainsCrash(mon.output[mon.curPos:]) { - return mon.extractError("unknown error"), true + return mon.extractErrors("unknown error"), true } if len(mon.output) > 2*mon.beforeContext { copy(mon.output, mon.output[len(mon.output)-mon.beforeContext:]) @@ -455,7 +455,7 @@ func (mon *monitor) appendOutput(out []byte) (*report.Report, bool) { return nil, false } -func (mon *monitor) extractError(defaultError string) *report.Report { +func (mon *monitor) extractErrors(defaultError string) []*report.Report { if mon.extractCalled { panic("extractError called twice") } @@ -466,7 +466,7 @@ func (mon *monitor) extractError(defaultError string) *report.Report { } diagOutput, diagWait := []byte{}, false if defaultError != "" { - diagOutput, diagWait = mon.inst.diagnose(mon.createReport(defaultError)) + diagOutput, diagWait = mon.inst.diagnose(mon.createReports(defaultError)) } // Give it some time to finish writing the error message. // But don't wait for "no output", we already waited enough. @@ -480,45 +480,52 @@ func (mon *monitor) extractError(defaultError string) *report.Report { } if defaultError == "" && mon.reporter.ContainsCrash(mon.output[mon.curPos:]) { // We did not call Diagnose above because we thought there is no error, so call it now. - diagOutput, diagWait = mon.inst.diagnose(mon.createReport(defaultError)) + diagOutput, diagWait = mon.inst.diagnose(mon.createReports(defaultError)) if diagWait { mon.waitForOutput() } } - rep := mon.createReport(defaultError) - if rep == nil { + reps := mon.createReports(defaultError) + if len(reps) == 0 { return nil } if len(diagOutput) > 0 { - rep.Output = append(rep.Output, vmDiagnosisStart...) - rep.Output = append(rep.Output, diagOutput...) + reps[0].Output = append(reps[0].Output, vmDiagnosisStart...) + reps[0].Output = append(reps[0].Output, diagOutput...) } - return rep + return reps } -func (mon *monitor) createReport(defaultError string) *report.Report { - rep := mon.reporter.ParseFrom(mon.output, mon.curPos) - if rep == nil { - if defaultError == "" { - return nil - } - typ := crash.UnknownType - if defaultError == lostConnectionCrash { - typ = crash.LostConnection +func (mon *monitor) createReports(defaultError string) []*report.Report { + curPos := mon.curPos + var res []*report.Report + for { + rep := mon.reporter.ParseFrom(mon.output, curPos) + if rep == nil { + if defaultError == "" || len(res) > 0 { + return res + } + typ := crash.UnknownType + if defaultError == lostConnectionCrash { + typ = crash.LostConnection + } + return []*report.Report{{ + Title: defaultError, + Output: mon.output, + Suppressed: report.IsSuppressed(mon.reporter, mon.output), + Type: typ, + }} } - return &report.Report{ - Title: defaultError, - Output: mon.output, - Suppressed: report.IsSuppressed(mon.reporter, mon.output), - Type: typ, + curPos = rep.SkipPos + start := max(rep.StartPos-mon.beforeContext, 0) + end := min(rep.EndPos+mon.afterContext, len(rep.Output)) + rep.Output = rep.Output[start:end] + rep.StartPos -= start + rep.EndPos -= start + if len(res) == 0 || (len(res) > 0 && !rep.Corrupted && !rep.Suppressed) { + res = append(res, rep) } } - start := max(rep.StartPos-mon.beforeContext, 0) - end := min(rep.EndPos+mon.afterContext, len(rep.Output)) - rep.Output = rep.Output[start:end] - rep.StartPos -= start - rep.EndPos -= start - return rep } func (mon *monitor) waitForOutput() { diff --git a/vm/vm_test.go b/vm/vm_test.go index 5034b1fa3a10..446898bd6199 100644 --- a/vm/vm_test.go +++ b/vm/vm_test.go @@ -7,6 +7,7 @@ import ( "bytes" "context" "fmt" + "strings" "testing" "time" @@ -15,6 +16,7 @@ import ( "github.com/google/syzkaller/pkg/report/crash" "github.com/google/syzkaller/sys/targets" "github.com/google/syzkaller/vm/vmimpl" + "github.com/stretchr/testify/assert" ) type testPool struct { @@ -349,8 +351,7 @@ func TestMonitorExecution(t *testing.T) { } } -func testMonitorExecution(t *testing.T, test *Test) { - dir := t.TempDir() +func makeLinuxAMD64Futex(t *testing.T) (*Instance, *report.Reporter) { cfg := &mgrconfig.Config{ Derived: mgrconfig.Derived{ TargetOS: targets.Linux, @@ -363,14 +364,14 @@ func testMonitorExecution(t *testing.T, test *Test) { }, SysTarget: targets.Get(targets.Linux, targets.AMD64), }, - Workdir: dir, + Workdir: t.TempDir(), Type: "test", } pool, err := Create(cfg, false) if err != nil { t.Fatal(err) } - defer pool.Close() + t.Cleanup(func() { pool.Close() }) reporter, err := report.NewReporter(cfg) if err != nil { t.Fatal(err) @@ -379,7 +380,12 @@ func testMonitorExecution(t *testing.T, test *Test) { if err != nil { t.Fatal(err) } - defer inst.Close() + t.Cleanup(func() { inst.Close() }) + return inst, reporter +} + +func testMonitorExecution(t *testing.T, test *Test) { + inst, reporter := makeLinuxAMD64Futex(t) testInst := inst.impl.(*testInstance) testInst.diagnoseBug = test.DiagnoseBug testInst.diagnoseNoWait = test.DiagnoseNoWait @@ -399,7 +405,7 @@ func testMonitorExecution(t *testing.T, test *Test) { test.BodyExecuting(testInst.outc, testInst.errc, inject) done <- true }() - _, rep, err := inst.Run(context.Background(), reporter, "", + _, reps, err := inst.Run(context.Background(), reporter, "", withTestRunOptionsDefaults(), WithExitCondition(test.Exit), WithEarlyFinishCb(func() { finishCalled++ }), @@ -412,15 +418,16 @@ func testMonitorExecution(t *testing.T, test *Test) { if finishCalled != 1 { t.Fatalf("finish callback is called %v times", finishCalled) } - if test.Report != nil && rep == nil { + if test.Report != nil && len(reps) == 0 { t.Fatalf("got no report") } - if test.Report == nil && rep != nil { - t.Fatalf("got unexpected report: %v", rep.Title) + if test.Report == nil && len(reps) != 0 { + t.Fatalf("got unexpected report: %v", reps[0].Title) } if test.Report == nil { return } + rep := reps[0] if test.Report.Title != rep.Title { t.Fatalf("want title %q, got title %q", test.Report.Title, rep.Title) } @@ -450,3 +457,157 @@ func TestVMType(t *testing.T) { } } } + +func TestExtractMultipleErrors(t *testing.T) { + inst, reporter := makeLinuxAMD64Futex(t) + mon := &monitor{ + RunOptions: &RunOptions{}, + inst: inst, + reporter: reporter, + output: []byte(validKASANReport + strings.Repeat(someLine, 10) + validKASANReport), + } + reps := mon.extractErrors("unknown error") + assert.Len(t, reps, 2, "expected to see 2 reports, got %v", len(reps)) + assert.Equal(t, reps[0].Title, reps[1].Title) + assert.False(t, reps[0].Corrupted) + assert.False(t, reps[1].Corrupted) +} + +const someLine = "[ 96.999999] some message \n" +const validKASANReport = ` +[ 96.262735] BUG: KASAN: double-free or invalid-free in selinux_tun_dev_free_security+0x15/0x20 +[ 96.271481] +[ 96.273098] CPU: 0 PID: 11514 Comm: syz-executor5 Not tainted 4.12.0-rc7+ #2 +[ 96.280268] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 +[ 96.289602] Call Trace: +[ 96.292180] dump_stack+0x194/0x257 +[ 96.295796] ? arch_local_irq_restore+0x53/0x53 +[ 96.300454] ? load_image_and_restore+0x10f/0x10f +[ 96.305299] ? selinux_tun_dev_free_security+0x15/0x20 +[ 96.310565] print_address_description+0x7f/0x260 +[ 96.315393] ? selinux_tun_dev_free_security+0x15/0x20 +[ 96.320656] ? selinux_tun_dev_free_security+0x15/0x20 +[ 96.325919] kasan_report_double_free+0x55/0x80 +[ 96.330577] kasan_slab_free+0xa0/0xc0 +[ 96.334450] kfree+0xd3/0x260 +[ 96.337545] selinux_tun_dev_free_security+0x15/0x20 +[ 96.342636] security_tun_dev_free_security+0x48/0x80 +[ 96.347822] __tun_chr_ioctl+0x2cc1/0x3d60 +[ 96.352054] ? tun_chr_close+0x60/0x60 +[ 96.355925] ? lock_downgrade+0x990/0x990 +[ 96.360059] ? lock_release+0xa40/0xa40 +[ 96.364025] ? __lock_is_held+0xb6/0x140 +[ 96.368213] ? check_same_owner+0x320/0x320 +[ 96.372530] ? tun_chr_compat_ioctl+0x30/0x30 +[ 96.377005] tun_chr_ioctl+0x2a/0x40 +[ 96.380701] ? tun_chr_ioctl+0x2a/0x40 +[ 96.385099] do_vfs_ioctl+0x1b1/0x15c0 +[ 96.388981] ? ioctl_preallocate+0x2d0/0x2d0 +[ 96.393378] ? selinux_capable+0x40/0x40 +[ 96.397430] ? SyS_futex+0x2b0/0x3a0 +[ 96.401147] ? security_file_ioctl+0x89/0xb0 +[ 96.405547] SyS_ioctl+0x8f/0xc0 +[ 96.408912] entry_SYSCALL_64_fastpath+0x1f/0xbe +[ 96.413651] RIP: 0033:0x4512c9 +[ 96.416824] RSP: 002b:00007fc65827bc08 EFLAGS: 00000216 ORIG_RAX: 0000000000000010 +[ 96.424603] RAX: ffffffffffffffda RBX: 0000000000718000 RCX: 00000000004512c9 +[ 96.431863] RDX: 000000002053c000 RSI: 00000000400454ca RDI: 0000000000000005 +[ 96.439133] RBP: 0000000000000082 R08: 0000000000000000 R09: 0000000000000000 +[ 96.446389] R10: 0000000000000000 R11: 0000000000000216 R12: 00000000004baa97 +[ 96.453647] R13: 00000000ffffffff R14: 0000000020124ff3 R15: 0000000000000000 +[ 96.460931] +[ 96.462552] Allocated by task 11514: +[ 96.466258] save_stack_trace+0x16/0x20 +[ 96.470212] save_stack+0x43/0xd0 +[ 96.473649] kasan_kmalloc+0xaa/0xd0 +[ 96.477347] kmem_cache_alloc_trace+0x101/0x6f0 +[ 96.481995] selinux_tun_dev_alloc_security+0x49/0x170 +[ 96.487250] security_tun_dev_alloc_security+0x6d/0xa0 +[ 96.492508] __tun_chr_ioctl+0x16bc/0x3d60 +[ 96.496722] tun_chr_ioctl+0x2a/0x40 +[ 96.500417] do_vfs_ioctl+0x1b1/0x15c0 +[ 96.504282] SyS_ioctl+0x8f/0xc0 +[ 96.507630] entry_SYSCALL_64_fastpath+0x1f/0xbe +[ 96.512367] +[ 96.513973] Freed by task 11514: +[ 96.517323] save_stack_trace+0x16/0x20 +[ 96.521276] save_stack+0x43/0xd0 +[ 96.524709] kasan_slab_free+0x6e/0xc0 +[ 96.528577] kfree+0xd3/0x260 +[ 96.531666] selinux_tun_dev_free_security+0x15/0x20 +[ 96.536747] security_tun_dev_free_security+0x48/0x80 +[ 96.541918] tun_free_netdev+0x13b/0x1b0 +[ 96.545959] register_netdevice+0x8d0/0xee0 +[ 96.550260] __tun_chr_ioctl+0x1bae/0x3d60 +[ 96.554475] tun_chr_ioctl+0x2a/0x40 +[ 96.558169] do_vfs_ioctl+0x1b1/0x15c0 +[ 96.562035] SyS_ioctl+0x8f/0xc0 +[ 96.565385] entry_SYSCALL_64_fastpath+0x1f/0xbe +[ 96.570116] +[ 96.571724] The buggy address belongs to the object at ffff8801d5961a40 +[ 96.571724] which belongs to the cache kmalloc-32 of size 32 +[ 96.584186] The buggy address is located 0 bytes inside of +[ 96.584186] 32-byte region [ffff8801d5961a40, ffff8801d5961a60) +[ 96.595775] The buggy address belongs to the page: +[ 96.600686] page:ffffea00066b8d38 count:1 mapcount:0 mapping:ffff8801d5961000 index:0xffff8801d5961fc1 +[ 96.610118] flags: 0x200000000000100(slab) +[ 96.614335] raw: 0200000000000100 ffff8801d5961000 ffff8801d5961fc1 000000010000003f +[ 96.622292] raw: ffffea0006723300 ffffea00066738b8 ffff8801dbc00100 +[ 96.628675] page dumped because: kasan: bad access detected +[ 96.634373] +[ 96.635978] Memory state around the buggy address: +[ 96.640884] ffff8801d5961900: 00 00 01 fc fc fc fc fc 00 00 00 fc fc fc fc fc +[ 96.648222] ffff8801d5961980: 00 00 00 00 fc fc fc fc fb fb fb fb fc fc fc fc +[ 96.655567] >ffff8801d5961a00: 00 00 00 fc fc fc fc fc fb fb fb fb fc fc fc fc +[ 96.663255] ^ +[ 96.668685] ffff8801d5961a80: fb fb fb fb fc fc fc fc 00 00 00 fc fc fc fc fc +[ 96.676022] ffff8801d5961b00: 04 fc fc fc fc fc fc fc fb fb fb fb fc fc fc fc +[ 96.683357] ================================================================== +[ 96.690692] Disabling lock debugging due to kernel taint +[ 96.696117] Kernel panic - not syncing: panic_on_warn set ... +[ 96.696117] +[ 96.703470] CPU: 0 PID: 11514 Comm: syz-executor5 Tainted: G B 4.12.0-rc7+ #2 +[ 96.711847] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 +[ 96.721354] Call Trace: +[ 96.723926] dump_stack+0x194/0x257 +[ 96.727539] ? arch_local_irq_restore+0x53/0x53 +[ 96.732366] ? kasan_end_report+0x32/0x50 +[ 96.736497] ? lock_downgrade+0x990/0x990 +[ 96.740631] panic+0x1e4/0x3fb +[ 96.743807] ? percpu_up_read_preempt_enable.constprop.38+0xae/0xae +[ 96.750194] ? add_taint+0x40/0x50 +[ 96.753723] ? selinux_tun_dev_free_security+0x15/0x20 +[ 96.758976] ? selinux_tun_dev_free_security+0x15/0x20 +[ 96.764233] kasan_end_report+0x50/0x50 +[ 96.768192] kasan_report_double_free+0x72/0x80 +[ 96.772843] kasan_slab_free+0xa0/0xc0 +[ 96.776711] kfree+0xd3/0x260 +[ 96.779802] selinux_tun_dev_free_security+0x15/0x20 +[ 96.784886] security_tun_dev_free_security+0x48/0x80 +[ 96.790061] __tun_chr_ioctl+0x2cc1/0x3d60 +[ 96.794285] ? tun_chr_close+0x60/0x60 +[ 96.798152] ? lock_downgrade+0x990/0x990 +[ 96.802803] ? lock_release+0xa40/0xa40 +[ 96.806763] ? __lock_is_held+0xb6/0x140 +[ 96.810829] ? check_same_owner+0x320/0x320 +[ 96.815137] ? tun_chr_compat_ioctl+0x30/0x30 +[ 96.819611] tun_chr_ioctl+0x2a/0x40 +[ 96.823306] ? tun_chr_ioctl+0x2a/0x40 +[ 96.827181] do_vfs_ioctl+0x1b1/0x15c0 +[ 96.831057] ? ioctl_preallocate+0x2d0/0x2d0 +[ 96.835450] ? selinux_capable+0x40/0x40 +[ 96.839494] ? SyS_futex+0x2b0/0x3a0 +[ 96.843200] ? security_file_ioctl+0x89/0xb0 +[ 96.847590] SyS_ioctl+0x8f/0xc0 +[ 96.850941] entry_SYSCALL_64_fastpath+0x1f/0xbe +[ 96.855676] RIP: 0033:0x4512c9 +[ 96.859020] RSP: 002b:00007fc65827bc08 EFLAGS: 00000216 ORIG_RAX: 0000000000000010 +[ 96.866708] RAX: ffffffffffffffda RBX: 0000000000718000 RCX: 00000000004512c9 +[ 96.873956] RDX: 000000002053c000 RSI: 00000000400454ca RDI: 0000000000000005 +[ 96.881208] RBP: 0000000000000082 R08: 0000000000000000 R09: 0000000000000000 +[ 96.888461] R10: 0000000000000000 R11: 0000000000000216 R12: 00000000004baa97 +[ 96.895708] R13: 00000000ffffffff R14: 0000000020124ff3 R15: 0000000000000000 +[ 96.903943] Dumping ftrace buffer: +[ 96.907460] (ftrace buffer empty) +[ 96.911148] Kernel Offset: disabled +`