From f497821174aa248c2a15e726e30f81aac61b5779 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Daniel=20Mart=C3=AD?= Date: Sat, 22 Jan 2022 12:03:56 +0000 Subject: [PATCH] redesign benchmark to be more useful and realistic MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit First, join the two benchmarks into one. The previous "cached" benchmark was borderline pointless, as it built the same package with the existing output binary, so it would quickly realise it had nothing to do and take ~100ms. The previous "noncached" benchmark input had no dependencies, so it was only really benchmarking the non-obfuscation of the runtime. All in all, neither benchmark measured obfuscating multiple packages. The new benchmark reuses the "cached" input, but with GOCACHE="*", meaning that we now obfuscate dozens of standard library packages. Each iteration first does a built from scratch, the worst case scenario, and then does an incremental rebuild of just the main package, which is the closest to a best case scenario without being a no-op. Since each iteration now performs both kinds of builds, we include a new "cached-time" metric to report what portion of the "time" metric corresponds to the incremental build. Thus, we can see a clean build takes ~11s, and a cached takes ~0.3s: name time/op Build-16 11.6s ± 1% name bin-B Build-16 5.34M ± 0% name cached-time/op Build-16 326ms ± 5% name sys-time/op Build-16 184ms ±13% name user-time/op Build-16 611ms ± 5% The benchmark is also no logner parallel; see the docs. Note that the old benchmark also reported bin-B incorrectly, as it looked at the binary size of garble itself, not the input program. --- bench_test.go | 145 +++++++++++++++--------- go.mod | 3 + go.sum | 11 +- testdata/bench-nocache/main.go | 16 --- testdata/{bench-cache => bench}/main.go | 3 + 5 files changed, 108 insertions(+), 70 deletions(-) delete mode 100644 testdata/bench-nocache/main.go rename testdata/{bench-cache => bench}/main.go (78%) diff --git a/bench_test.go b/bench_test.go index a47c993..6519fff 100644 --- a/bench_test.go +++ b/bench_test.go @@ -4,80 +4,121 @@ package main import ( + _ "embed" + "flag" + "fmt" "os" "os/exec" "path/filepath" + "regexp" "runtime" + "strings" "testing" + "time" + + qt "github.com/frankban/quicktest" ) -// BenchmarkBuild is a parallel benchmark for 'garble build' on a fairly simple +//go:embed testdata/bench/main.go +var benchSourceMain []byte + +var ( + rxBuiltRuntime = regexp.MustCompile(`(?m)^runtime$`) + rxBuiltMain = regexp.MustCompile(`(?m)^test/main$`) +) + +// BenchmarkBuild is a benchmark for 'garble build' on a fairly simple // main package with a handful of standard library depedencies. // // We use a real garble binary and exec it, to simulate what the real user would // run. The real obfuscation and compilation will happen in sub-processes // anyway, so skipping one exec layer doesn't help us in any way. // +// The benchmark isn't parallel, because in practice users build once at a time, +// and each build already spawns concurrent processes and goroutines to do work. +// // At the moment, each iteration takes 1-2s on a laptop, so we can't make the // benchmark include any more features unless we make it significantly faster. func BenchmarkBuild(b *testing.B) { + // As of Go 1.17, using -benchtime=Nx with N larger than 1 results in two + // calls to BenchmarkBuild, with the first having b.N==1 to discover + // sub-benchmarks. Unfortunately, we do a significant amount of work both + // during setup and during that first iteration, which is pointless. + // To avoid that, detect the scenario in a hacky way, and return early. + // See https://github.com/golang/go/issues/32051. + benchtime := flag.Lookup("test.benchtime").Value.String() + if b.N == 1 && strings.HasSuffix(benchtime, "x") && benchtime != "1x" { + return + } + garbleBin := filepath.Join(b.TempDir(), "garble") if runtime.GOOS == "windows" { garbleBin += ".exe" } + err := exec.Command("go", "build", "-o="+garbleBin).Run() + qt.Assert(b, err, qt.IsNil) + + // We collect extra metrics. + var userTime, systemTime int64 + + var cachedTime int64 - if err := exec.Command("go", "build", "-o="+garbleBin).Run(); err != nil { - b.Fatalf("building garble: %v", err) + outputBin := filepath.Join(b.TempDir(), "output") + sourceDir := filepath.Join(b.TempDir(), "src") + err = os.Mkdir(sourceDir, 0o777) + qt.Assert(b, err, qt.IsNil) + + writeSourceFile := func(name string, content []byte) { + err := os.WriteFile(filepath.Join(sourceDir, name), content, 0o666) + qt.Assert(b, err, qt.IsNil) } + writeSourceFile("go.mod", []byte("module test/main")) + writeSourceFile("main.go", benchSourceMain) + + b.ResetTimer() + for i := 0; i < b.N; i++ { + // First we do a fresh build, using a new GOCACHE. + // and the second does an incremental rebuild reusing the cache. + gocache, err := os.MkdirTemp(b.TempDir(), "gocache-*") + qt.Assert(b, err, qt.IsNil) + env := append(os.Environ(), "GOGARBLE=*", "GOCACHE="+gocache) + args := []string{"build", "-v", "-o=" + outputBin, sourceDir} + + cmd := exec.Command(garbleBin, args...) + cmd.Env = env + cmd.Dir = sourceDir + + out, err := cmd.CombinedOutput() + qt.Assert(b, err, qt.IsNil, qt.Commentf("output: %s", out)) + // Ensure that we built all packages, as expected. + qt.Assert(b, rxBuiltRuntime.Match(out), qt.IsTrue) + qt.Assert(b, rxBuiltMain.Match(out), qt.IsTrue) - for _, name := range [...]string{"Cache", "NoCache"} { - b.Run(name, func(b *testing.B) { - buildArgs := []string{"build", "-o=" + b.TempDir()} - switch name { - case "Cache": - buildArgs = append(buildArgs, "./testdata/bench-cache") - - // Ensure the build cache is warm, - // for the sake of consistent results. - cmd := exec.Command(garbleBin, buildArgs...) - if out, err := cmd.CombinedOutput(); err != nil { - b.Fatalf("%v: %s", err, out) - } - case "NoCache": - buildArgs = append(buildArgs, "./testdata/bench-nocache") - default: - b.Fatalf("unknown name: %q", name) - } - - // We collect extra metrics. - var userTime, systemTime int64 - - b.ResetTimer() - b.RunParallel(func(pb *testing.PB) { - for pb.Next() { - cmd := exec.Command(garbleBin, buildArgs...) - if name == "NoCache" { - gocache, err := os.MkdirTemp(b.TempDir(), "gocache-*") - if err != nil { - b.Fatal(err) - } - cmd.Env = append(os.Environ(), "GOCACHE="+gocache) - } - if out, err := cmd.CombinedOutput(); err != nil { - b.Fatalf("%v: %s", err, out) - } - - userTime += int64(cmd.ProcessState.UserTime()) - systemTime += int64(cmd.ProcessState.SystemTime()) - } - }) - b.ReportMetric(float64(userTime)/float64(b.N), "user-ns/op") - b.ReportMetric(float64(systemTime)/float64(b.N), "sys-ns/op") - info, err := os.Stat(garbleBin) - if err != nil { - b.Fatal(err) - } - b.ReportMetric(float64(info.Size()), "bin-B") - }) + // The cached rebuild will reuse all dependencies, + // but rebuild the main package itself. + cachedStart := time.Now() + writeSourceFile("rebuild.go", []byte(fmt.Sprintf("package main\nvar v%d int", i))) + + cmd = exec.Command(garbleBin, args...) + cmd.Env = env + cmd.Dir = sourceDir + + out, err = cmd.CombinedOutput() + qt.Assert(b, err, qt.IsNil, qt.Commentf("output: %s", out)) + // Ensure that we only rebuilt the main package, as expected. + qt.Assert(b, rxBuiltRuntime.Match(out), qt.IsFalse) + qt.Assert(b, rxBuiltMain.Match(out), qt.IsTrue) + + userTime += int64(cmd.ProcessState.UserTime()) + systemTime += int64(cmd.ProcessState.SystemTime()) + cachedTime += time.Since(cachedStart).Nanoseconds() + } + b.ReportMetric(float64(cachedTime)/float64(b.N), "cached-ns/op") + b.ReportMetric(float64(userTime)/float64(b.N), "user-ns/op") + b.ReportMetric(float64(systemTime)/float64(b.N), "sys-ns/op") + info, err := os.Stat(outputBin) + if err != nil { + b.Fatal(err) } + b.ReportMetric(float64(info.Size()), "bin-B") } diff --git a/go.mod b/go.mod index 0dfb840..d7b6774 100644 --- a/go.mod +++ b/go.mod @@ -3,6 +3,7 @@ module mvdan.cc/garble go 1.17 require ( + github.com/frankban/quicktest v1.14.0 github.com/google/go-cmp v0.5.7 github.com/rogpeppe/go-internal v1.8.1 golang.org/x/mod v0.5.1 @@ -10,6 +11,8 @@ require ( ) require ( + github.com/kr/pretty v0.3.0 // indirect + github.com/kr/text v0.2.0 // indirect github.com/pkg/diff v0.0.0-20210226163009-20ebb0f2a09e // indirect golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1 // indirect gopkg.in/errgo.v2 v2.1.0 // indirect diff --git a/go.sum b/go.sum index c691c49..3d293b6 100644 --- a/go.sum +++ b/go.sum @@ -1,12 +1,19 @@ +github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E= +github.com/frankban/quicktest v1.14.0 h1:+cqqvzZV87b4adx/5ayVOaYZ2CrvM4ejQvUdBzPPUss= +github.com/frankban/quicktest v1.14.0/go.mod h1:NeW+ay9A/U67EYXNFA1nPE8e/tnQv/09mUdL/ijj8og= +github.com/google/go-cmp v0.5.6/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= github.com/google/go-cmp v0.5.7 h1:81/ik6ipDQS2aGcBfIN5dHDB36BwrStyeAQquSYCV4o= github.com/google/go-cmp v0.5.7/go.mod h1:n+brtR0CgQNWTVd5ZUFpTBC8YFBDLK/h/bpaJ8/DtOE= -github.com/kr/pretty v0.1.0 h1:L/CwN0zerZDmRFUapSPitk6f+Q3+0za1rQkzVuMiMFI= github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORNo= +github.com/kr/pretty v0.3.0 h1:WgNl7dwNpEZ6jJ9k1snq4pZsg7DOEN8hP9Xw0Tsjwk0= +github.com/kr/pretty v0.3.0/go.mod h1:640gp4NfQd8pI5XOwp5fnNeVWj67G7CFk/SaSQn7NBk= github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ= -github.com/kr/text v0.1.0 h1:45sCR5RtlFHMR4UwH9sdQ5TC8v0qDQCHnXt+kaKSTVE= github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI= +github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY= +github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE= github.com/pkg/diff v0.0.0-20210226163009-20ebb0f2a09e h1:aoZm08cpOy4WuID//EZDgcC4zIxODThtZNPirFr42+A= github.com/pkg/diff v0.0.0-20210226163009-20ebb0f2a09e/go.mod h1:pJLUxLENpZxwdsKMEsNbx1VGcRFpLqf3715MtcvvzbA= +github.com/rogpeppe/go-internal v1.6.1/go.mod h1:xXDCJY+GAPziupqXw64V24skbSoqbTEfhy4qGm1nDQc= github.com/rogpeppe/go-internal v1.8.1 h1:geMPLpDpQOgVyCg5z5GoRwLHepNdb71NXb67XFkP+Eg= github.com/rogpeppe/go-internal v1.8.1/go.mod h1:JeRgkft04UBgHMgCIwADu4Pn6Mtm5d4nPKWu0nJ5d+o= github.com/yuin/goldmark v1.4.1/go.mod h1:mwnBkeHKe2W/ZEtQ+71ViKU8L12m81fl3OWwC1Zlc8k= diff --git a/testdata/bench-nocache/main.go b/testdata/bench-nocache/main.go deleted file mode 100644 index bcd0eb0..0000000 --- a/testdata/bench-nocache/main.go +++ /dev/null @@ -1,16 +0,0 @@ -// Copyright (c) 2020, The Garble Authors. -// See LICENSE for licensing information. - -// A simple main package with some names to obfuscate. -// No dependencies, since each benchmark iteration will rebuild all deps. - -package main - -var globalVar = "global value" - -func globalFunc() { println("global func body") } - -func main() { - println(globalVar) - globalFunc() -} diff --git a/testdata/bench-cache/main.go b/testdata/bench/main.go similarity index 78% rename from testdata/bench-cache/main.go rename to testdata/bench/main.go index 3ecbabf..748a367 100644 --- a/testdata/bench-cache/main.go +++ b/testdata/bench/main.go @@ -3,6 +3,7 @@ // A simple main package with some names to obfuscate. // With relatively heavy dependencies, as benchmark iterations use the build cache. +// We also use a mix of funcs, methods, fields, literals, etc. package main @@ -19,4 +20,6 @@ func main() { fmt.Println(globalVar) globalFunc() http.ListenAndServe("", nil) + client := http.Client{Transport: nil} + client.Do(nil) }