From 02483b6e8ecc8a21f9f525088905211671363d55 Mon Sep 17 00:00:00 2001 From: Andrey Konovalov Date: Mon, 19 Jun 2017 14:23:17 +0200 Subject: repro: move duration to Result --- pkg/repro/repro.go | 41 +++++++++++++++++++++-------------------- 1 file changed, 21 insertions(+), 20 deletions(-) (limited to 'pkg') diff --git a/pkg/repro/repro.go b/pkg/repro/repro.go index 93ecc24ef..bde09db20 100644 --- a/pkg/repro/repro.go +++ b/pkg/repro/repro.go @@ -21,9 +21,10 @@ import ( ) type Result struct { - Prog *prog.Prog - Opts csource.Options - CRepro bool + Prog *prog.Prog + Duration time.Duration + Opts csource.Options + CRepro bool } type context struct { @@ -135,6 +136,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er break } } + // Extract last program on every proc. procs := make(map[int]int) for i, ent := range entries { @@ -169,7 +171,6 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er // to catch races and hangs. Note that the max duration must be larger than // hang/no output detection duration in vm.MonitorExecution, which is currently set to 3 mins. var res *Result - var duration time.Duration for _, dur := range []time.Duration{10 * time.Second, 5 * time.Minute} { for _, ent := range suspected { opts.Fault = ent.Fault @@ -184,10 +185,10 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er } if crashed { res = &Result{ - Prog: ent.P, - Opts: opts, + Prog: ent.P, + Duration: dur * 3 / 2, + Opts: opts, } - duration = dur * 3 / 2 break } } @@ -209,7 +210,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er call = res.Opts.FaultCall } res.Prog, res.Opts.FaultCall = prog.Minimize(res.Prog, call, func(p1 *prog.Prog, callIndex int) bool { - crashed, err := ctx.testProg(p1, duration, res.Opts) + crashed, err := ctx.testProg(p1, res.Duration, res.Opts) if err != nil { Logf(1, "reproducing crash '%v': minimization failed with %v", ctx.crashDesc, err) return false @@ -220,14 +221,14 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er // Try to "minimize" threaded/collide/sandbox/etc to find simpler reproducer. opts = res.Opts opts.Collide = false - crashed, err := ctx.testProg(res.Prog, duration, opts) + crashed, err := ctx.testProg(res.Prog, res.Duration, opts) if err != nil { return res, err } if crashed { res.Opts = opts opts.Threaded = false - crashed, err := ctx.testProg(res.Prog, duration, opts) + crashed, err := ctx.testProg(res.Prog, res.Duration, opts) if err != nil { return res, err } @@ -238,7 +239,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er if res.Opts.Sandbox == "namespace" { opts = res.Opts opts.Sandbox = "none" - crashed, err := ctx.testProg(res.Prog, duration, opts) + crashed, err := ctx.testProg(res.Prog, res.Duration, opts) if err != nil { return res, err } @@ -249,7 +250,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er if res.Opts.Procs > 1 { opts = res.Opts opts.Procs = 1 - crashed, err := ctx.testProg(res.Prog, duration, opts) + crashed, err := ctx.testProg(res.Prog, res.Duration, opts) if err != nil { return res, err } @@ -260,7 +261,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er if res.Opts.Repeat { opts = res.Opts opts.Repeat = false - crashed, err := ctx.testProg(res.Prog, duration, opts) + crashed, err := ctx.testProg(res.Prog, res.Duration, opts) if err != nil { return res, err } @@ -270,7 +271,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er } // Try triggering crash with a C reproducer. - crashed, err = ctx.testCProg(res.Prog, duration, res.Opts) + crashed, err = ctx.testCProg(res.Prog, res.Duration, res.Opts) if err != nil { return res, err } @@ -283,7 +284,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er if res.Opts.EnableTun { opts = res.Opts opts.EnableTun = false - crashed, err := ctx.testCProg(res.Prog, duration, opts) + crashed, err := ctx.testCProg(res.Prog, res.Duration, opts) if err != nil { return res, err } @@ -294,7 +295,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er if res.Opts.Sandbox != "" { opts = res.Opts opts.Sandbox = "" - crashed, err := ctx.testCProg(res.Prog, duration, opts) + crashed, err := ctx.testCProg(res.Prog, res.Duration, opts) if err != nil { return res, err } @@ -305,7 +306,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er if res.Opts.UseTmpDir { opts = res.Opts opts.UseTmpDir = false - crashed, err := ctx.testCProg(res.Prog, duration, opts) + crashed, err := ctx.testCProg(res.Prog, res.Duration, opts) if err != nil { return res, err } @@ -316,7 +317,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er if res.Opts.HandleSegv { opts = res.Opts opts.HandleSegv = false - crashed, err := ctx.testCProg(res.Prog, duration, opts) + crashed, err := ctx.testCProg(res.Prog, res.Duration, opts) if err != nil { return res, err } @@ -327,7 +328,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er if res.Opts.WaitRepeat { opts = res.Opts opts.WaitRepeat = false - crashed, err := ctx.testCProg(res.Prog, duration, opts) + crashed, err := ctx.testCProg(res.Prog, res.Duration, opts) if err != nil { return res, err } @@ -338,7 +339,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er if res.Opts.Debug { opts = res.Opts opts.Debug = false - crashed, err := ctx.testCProg(res.Prog, duration, opts) + crashed, err := ctx.testCProg(res.Prog, res.Duration, opts) if err != nil { return res, err } -- cgit mrf-deployment From 864a841818e1764fab25cae8f3a415e39b01f836 Mon Sep 17 00:00:00 2001 From: Andrey Konovalov Date: Mon, 19 Jun 2017 14:42:50 +0200 Subject: repro: split ctx.repro() into smaller methods --- pkg/repro/repro.go | 89 +++++++++++++++++++++++++++++++++++++++--------------- 1 file changed, 65 insertions(+), 24 deletions(-) (limited to 'pkg') diff --git a/pkg/repro/repro.go b/pkg/repro/repro.go index bde09db20..a3f54b9a5 100644 --- a/pkg/repro/repro.go +++ b/pkg/repro/repro.go @@ -128,15 +128,7 @@ func Run(crashLog []byte, cfg *mgrconfig.Config, vmPool *vm.Pool, vmIndexes []in return res, err } -func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, error) { - // Cut programs that were executed after crash. - for i, ent := range entries { - if ent.Start > crashStart { - entries = entries[:i] - break - } - } - +func (ctx *context) reproExtractProg(entries []*prog.LogEntry) (*Result, error) { // Extract last program on every proc. procs := make(map[int]int) for i, ent := range entries { @@ -165,6 +157,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er Debug: true, Repro: true, } + // Execute the suspected programs. // We first try to execute each program for 10 seconds, that should detect simple crashes // (i.e. no races and no hangs). Then we execute each program for 5 minutes @@ -200,11 +193,14 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er Logf(0, "reproducing crash '%v': no program crashed", ctx.crashDesc) return nil, nil } - defer func() { - res.Opts.Repro = false - }() + return res, nil +} + +func (ctx *context) reproMinimizeProg(res *Result) (*Result, error) { Logf(2, "reproducing crash '%v': minimizing guilty program", ctx.crashDesc) + + // Minimize calls and arguments. call := -1 if res.Opts.Fault { call = res.Opts.FaultCall @@ -218,8 +214,8 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er return crashed }, true) - // Try to "minimize" threaded/collide/sandbox/etc to find simpler reproducer. - opts = res.Opts + // Minimize repro options (threaded, collide, sandbox, etc). + opts := res.Opts opts.Collide = false crashed, err := ctx.testProg(res.Prog, res.Duration, opts) if err != nil { @@ -270,19 +266,27 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er } } + return res, nil +} + +func (ctx *context) reproExtractC(res *Result) (*Result, error) { + Logf(2, "reproducing crash '%v': testing C reproducer", ctx.crashDesc) + // Try triggering crash with a C reproducer. - crashed, err = ctx.testCProg(res.Prog, res.Duration, res.Opts) + crashed, err := ctx.testCProg(res.Prog, res.Duration, res.Opts) if err != nil { return res, err } res.CRepro = crashed - if !crashed { - return res, nil - } + return res, nil +} + +func (ctx *context) reproMinimizeC(res *Result) (*Result, error) { + Logf(2, "reproducing crash '%v': minimizing C reproducer", ctx.crashDesc) // Try to simplify the C reproducer. if res.Opts.EnableTun { - opts = res.Opts + opts := res.Opts opts.EnableTun = false crashed, err := ctx.testCProg(res.Prog, res.Duration, opts) if err != nil { @@ -293,7 +297,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er } } if res.Opts.Sandbox != "" { - opts = res.Opts + opts := res.Opts opts.Sandbox = "" crashed, err := ctx.testCProg(res.Prog, res.Duration, opts) if err != nil { @@ -304,7 +308,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er } } if res.Opts.UseTmpDir { - opts = res.Opts + opts := res.Opts opts.UseTmpDir = false crashed, err := ctx.testCProg(res.Prog, res.Duration, opts) if err != nil { @@ -315,7 +319,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er } } if res.Opts.HandleSegv { - opts = res.Opts + opts := res.Opts opts.HandleSegv = false crashed, err := ctx.testCProg(res.Prog, res.Duration, opts) if err != nil { @@ -326,7 +330,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er } } if res.Opts.WaitRepeat { - opts = res.Opts + opts := res.Opts opts.WaitRepeat = false crashed, err := ctx.testCProg(res.Prog, res.Duration, opts) if err != nil { @@ -337,7 +341,7 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er } } if res.Opts.Debug { - opts = res.Opts + opts := res.Opts opts.Debug = false crashed, err := ctx.testCProg(res.Prog, res.Duration, opts) if err != nil { @@ -351,6 +355,43 @@ func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, er return res, nil } +func (ctx *context) repro(entries []*prog.LogEntry, crashStart int) (*Result, error) { + // Cut programs that were executed after crash. + for i, ent := range entries { + if ent.Start > crashStart { + entries = entries[:i] + break + } + } + + res, err := ctx.reproExtractProg(entries) + if err != nil { + return res, err + } + + res, err = ctx.reproMinimizeProg(res) + if err != nil { + return res, err + } + + res, err = ctx.reproExtractC(res) + if err != nil { + return res, err + } + if !res.CRepro { + res.Opts.Repro = false + return res, nil + } + + res, err = ctx.reproMinimizeC(res) + if err != nil { + return res, err + } + + res.Opts.Repro = false + return res, nil +} + func (ctx *context) testProg(p *prog.Prog, duration time.Duration, opts csource.Options) (crashed bool, err error) { inst := <-ctx.instances if inst == nil { -- cgit mrf-deployment From a1e85a568848ec0e43b10b5d0658d130b175801d Mon Sep 17 00:00:00 2001 From: Andrey Konovalov Date: Mon, 19 Jun 2017 15:19:10 +0200 Subject: repro: try more programs with short duration --- pkg/repro/repro.go | 23 ++++++++++++++++++----- 1 file changed, 18 insertions(+), 5 deletions(-) (limited to 'pkg') diff --git a/pkg/repro/repro.go b/pkg/repro/repro.go index a3f54b9a5..167b03c09 100644 --- a/pkg/repro/repro.go +++ b/pkg/repro/repro.go @@ -41,6 +41,14 @@ type instance struct { executorBin string } +func reverseEntries(entries []*prog.LogEntry) []*prog.LogEntry { + last := len(entries) - 1 + for i := 0; i < len(entries)/2; i++ { + entries[i], entries[last-i] = entries[last-i], entries[i] + } + return entries +} + func Run(crashLog []byte, cfg *mgrconfig.Config, vmPool *vm.Pool, vmIndexes []int) (*Result, error) { if len(vmIndexes) == 0 { return nil, fmt.Errorf("no VMs provided") @@ -129,6 +137,8 @@ func Run(crashLog []byte, cfg *mgrconfig.Config, vmPool *vm.Pool, vmIndexes []in } func (ctx *context) reproExtractProg(entries []*prog.LogEntry) (*Result, error) { + Logf(2, "reproducing crash '%v': suspecting %v programs", ctx.crashDesc, len(entries)) + // Extract last program on every proc. procs := make(map[int]int) for i, ent := range entries { @@ -139,11 +149,11 @@ func (ctx *context) reproExtractProg(entries []*prog.LogEntry) (*Result, error) indices = append(indices, idx) } sort.Ints(indices) - var suspected []*prog.LogEntry + var lastEntries []*prog.LogEntry for i := len(indices) - 1; i >= 0; i-- { - suspected = append(suspected, entries[indices[i]]) + lastEntries = append(lastEntries, entries[indices[i]]) } - Logf(2, "reproducing crash '%v': suspecting %v programs", ctx.crashDesc, len(suspected)) + opts := csource.Options{ Threaded: true, Collide: true, @@ -163,9 +173,12 @@ func (ctx *context) reproExtractProg(entries []*prog.LogEntry) (*Result, error) // (i.e. no races and no hangs). Then we execute each program for 5 minutes // to catch races and hangs. Note that the max duration must be larger than // hang/no output detection duration in vm.MonitorExecution, which is currently set to 3 mins. + // Programs are executed in reverse order, usually the last program is the guilty one. + durations := []time.Duration{10 * time.Second, 5 * time.Minute} + suspected := [][]*prog.LogEntry{reverseEntries(entries), reverseEntries(lastEntries)} var res *Result - for _, dur := range []time.Duration{10 * time.Second, 5 * time.Minute} { - for _, ent := range suspected { + for i, dur := range durations { + for _, ent := range suspected[i] { opts.Fault = ent.Fault opts.FaultCall = ent.FaultCall opts.FaultNth = ent.FaultNth -- cgit mrf-deployment From 81990cb63316391a226e92ecda9e09dbe3bc8e1e Mon Sep 17 00:00:00 2001 From: Andrey Konovalov Date: Mon, 19 Jun 2017 15:31:06 +0200 Subject: repro: small log fix --- pkg/repro/repro.go | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) (limited to 'pkg') diff --git a/pkg/repro/repro.go b/pkg/repro/repro.go index 167b03c09..111ae42ed 100644 --- a/pkg/repro/repro.go +++ b/pkg/repro/repro.go @@ -283,7 +283,7 @@ func (ctx *context) reproMinimizeProg(res *Result) (*Result, error) { } func (ctx *context) reproExtractC(res *Result) (*Result, error) { - Logf(2, "reproducing crash '%v': testing C reproducer", ctx.crashDesc) + Logf(2, "reproducing crash '%v': extracting C reproducer", ctx.crashDesc) // Try triggering crash with a C reproducer. crashed, err := ctx.testCProg(res.Prog, res.Duration, res.Opts) @@ -471,7 +471,6 @@ func (ctx *context) testBin(bin string, duration time.Duration) (crashed bool, e if err != nil { return false, fmt.Errorf("failed to copy to VM: %v", err) } - Logf(2, "reproducing crash '%v': testing compiled C program", ctx.crashDesc) return ctx.testImpl(inst.Instance, bin, duration) } -- cgit mrf-deployment