func testProg(cfg *config.Config, p *prog.Prog, multiplier int, threaded, collide bool) (res bool) {
log.Printf("booting VM")
inst := <-instances
defer func() {
returnInstance(inst, res)
}()
pstr := p.Serialize()
progFile, err := fileutil.WriteTempFile(pstr)
if err != nil {
log.Fatalf("%v", err)
}
defer os.Remove(progFile)
bin, err := inst.Copy(progFile)
if err != nil {
log.Fatalf("failed to copy to VM: %v", err)
}
repeat := 100
timeoutSec := 10 * repeat / cfg.Procs
if threaded {
repeat *= 10
timeoutSec *= 1
}
repeat *= multiplier
timeoutSec *= multiplier
timeout := time.Duration(timeoutSec) * time.Second
command := fmt.Sprintf("%v -executor %v -cover=0 -procs=%v -repeat=%v -threaded=%v -collide=%v %v",
inst.execprogBin, inst.executorBin, cfg.Procs, repeat, threaded, collide, bin)
log.Printf("testing program (threaded=%v, collide=%v, repeat=%v, timeout=%v):\n%s\n",
threaded, collide, repeat, timeout, pstr)
return testImpl(inst, command, timeout)
}
func (ctx *context) testProg(p *prog.Prog, duration time.Duration, opts csource.Options, reboot bool) (crashed bool, err error) {
inst := <-ctx.instances
if inst == nil {
return false, fmt.Errorf("all VMs failed to boot")
}
defer func() {
ctx.returnInstance(inst, reboot, crashed)
}()
pstr := p.Serialize()
progFile, err := fileutil.WriteTempFile(pstr)
if err != nil {
return false, err
}
defer os.Remove(progFile)
vmProgFile, err := inst.Copy(progFile)
if err != nil {
return false, fmt.Errorf("failed to copy to VM: %v", err)
}
repeat := "1"
if opts.Repeat {
repeat = "0"
}
command := fmt.Sprintf("%v -executor %v -cover=0 -procs=%v -repeat=%v -sandbox %v -threaded=%v -collide=%v %v",
inst.execprogBin, inst.executorBin, opts.Procs, repeat, opts.Sandbox, opts.Threaded, opts.Collide, vmProgFile)
Logf(2, "reproducing crash '%v': testing program (duration=%v, %+v): %s",
ctx.crashDesc, duration, opts, p)
return ctx.testImpl(inst, command, duration)
}
func buildSource(t *testing.T, src []byte) string {
tmp, err := fileutil.WriteTempFile(src)
if err != nil {
t.Fatalf("%v", err)
}
defer os.Remove(tmp)
return buildProgram(t, tmp)
}
func testOne(t *testing.T, p *prog.Prog, opts Options) {
src := Write(p, opts)
srcf, err := fileutil.WriteTempFile(src)
if err != nil {
t.Logf("program:\n%s\n", p.Serialize())
t.Fatalf("%v", err)
}
defer os.Remove(srcf)
bin, err := Build(srcf)
if err != nil {
t.Logf("program:\n%s\n", p.Serialize())
t.Fatalf("%v", err)
}
defer os.Remove(bin)
}
func repro(cfg *config.Config, entries []*prog.LogEntry, crashLoc []int) {
// Cut programs that were executed after crash.
for i, ent := range entries {
if ent.Start > crashLoc[0] {
entries = entries[:i]
break
}
}
// Extract last program on every proc.
procs := make(map[int]int)
for i, ent := range entries {
procs[ent.Proc] = i
}
var indices []int
for _, idx := range procs {
indices = append(indices, idx)
}
sort.Ints(indices)
var suspected []*prog.LogEntry
for i := len(indices) - 1; i >= 0; i-- {
suspected = append(suspected, entries[indices[i]])
}
// Execute the suspected programs.
log.Printf("the suspected programs are:")
for _, ent := range suspected {
log.Printf("on proc %v:\n%s\n", ent.Proc, ent.P.Serialize())
}
var p *prog.Prog
multiplier := 1
for ; p == nil && multiplier <= 100; multiplier *= 10 {
for _, ent := range suspected {
if testProg(cfg, ent.P, multiplier, true, true) {
p = ent.P
break
}
}
}
if p == nil {
log.Printf("no program crashed")
return
}
log.Printf("minimizing program")
p, _ = prog.Minimize(p, -1, func(p1 *prog.Prog, callIndex int) bool {
return testProg(cfg, p1, multiplier, true, true)
})
opts := csource.Options{
Threaded: true,
Collide: true,
}
if testProg(cfg, p, multiplier, true, false) {
opts.Collide = false
if testProg(cfg, p, multiplier, false, false) {
opts.Threaded = false
}
}
src := csource.Write(p, opts)
log.Printf("C source:\n%s\n", src)
srcf, err := fileutil.WriteTempFile(src)
if err != nil {
log.Fatalf("%v", err)
}
bin, err := csource.Build(srcf)
if err != nil {
log.Fatalf("%v", err)
}
defer os.Remove(bin)
testBin(cfg, bin)
}
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
}
}
// Extract last program on every proc.
procs := make(map[int]int)
for i, ent := range entries {
procs[ent.Proc] = i
}
var indices []int
for _, idx := range procs {
indices = append(indices, idx)
}
sort.Ints(indices)
var suspected []*prog.LogEntry
for i := len(indices) - 1; i >= 0; i-- {
suspected = append(suspected, entries[indices[i]])
}
Logf(2, "reproducing crash '%v': suspecting %v programs", ctx.crashDesc, len(suspected))
opts := csource.Options{
Threaded: true,
Collide: true,
Repeat: true,
Procs: ctx.cfg.Procs,
Sandbox: ctx.cfg.Sandbox,
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
// 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 {
crashed, err := ctx.testProg(ent.P, dur, opts, true)
if err != nil {
return nil, err
}
if crashed {
res = &Result{
Prog: ent.P,
Opts: opts,
}
duration = dur * 3 / 2
break
}
}
if res != nil {
break
}
}
if res == nil {
Logf(0, "reproducing crash '%v': no program crashed", ctx.crashDesc)
return nil, nil
}
defer func() {
res.Opts.Repro = false
}()
Logf(2, "reproducing crash '%v': minimizing guilty program", ctx.crashDesc)
res.Prog, _ = prog.Minimize(res.Prog, -1, func(p1 *prog.Prog, callIndex int) bool {
crashed, err := ctx.testProg(p1, duration, res.Opts, false)
if err != nil {
Logf(1, "reproducing crash '%v': minimization failed with %v", ctx.crashDesc, err)
return false
}
return crashed
}, true)
// 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, false)
if err != nil {
return res, err
}
if crashed {
res.Opts = opts
opts.Threaded = false
crashed, err := ctx.testProg(res.Prog, duration, opts, false)
if err != nil {
return res, err
}
if crashed {
res.Opts = opts
}
}
if res.Opts.Sandbox == "namespace" {
opts = res.Opts
opts.Sandbox = "none"
crashed, err := ctx.testProg(res.Prog, duration, opts, false)
if err != nil {
return res, err
}
if crashed {
res.Opts = opts
}
}
if res.Opts.Procs > 1 {
opts = res.Opts
opts.Procs = 1
crashed, err := ctx.testProg(res.Prog, duration, opts, false)
if err != nil {
return res, err
}
if crashed {
res.Opts = opts
}
}
if res.Opts.Repeat {
opts = res.Opts
opts.Repeat = false
crashed, err := ctx.testProg(res.Prog, duration, opts, false)
if err != nil {
return res, err
}
if crashed {
res.Opts = opts
}
}
src, err := csource.Write(res.Prog, res.Opts)
if err != nil {
return res, err
}
srcf, err := fileutil.WriteTempFile(src)
if err != nil {
return res, err
}
bin, err := csource.Build(srcf)
if err != nil {
return res, err
}
defer os.Remove(bin)
crashed, err = ctx.testBin(bin, duration, false)
if err != nil {
return res, err
}
res.CRepro = crashed
return res, nil
}