Add Microbenchmarks for VIF/VC creations.
BenchmarkVIF_Dial:
Histogram (unit: us)
Count: 100000 Min: 4 Max: 7292 Avg: 14.39
------------------------------------------------------------
[ 4, 5) 1 0.0% 0.0%
[ 5, 6) 53395 53.4% 53.4% #####
[ 6, 9) 32558 32.6% 86.0% ###
[ 9, 14) 9596 9.6% 95.5% #
[ 14, 24) 2444 2.4% 98.0%
[ 24, 43) 1182 1.2% 99.2%
[ 43, 78) 400 0.4% 99.6%
[ 78, 141) 88 0.1% 99.7%
[ 141, 255) 52 0.1% 99.7%
[ 255, 462) 1 0.0% 99.7%
[ 462, 837) 17 0.0% 99.7%
[ 837, 1517) 77 0.1% 99.8%
[ 1517, 2747) 19 0.0% 99.8%
[ 2747, 4973) 157 0.2% 100.0%
[ 4973, 9001) 13 0.0% 100.0%
[ 9001, 16288) 0 0.0% 100.0%
[16288, inf) 0 0.0% 100.0%
100000 17919 ns/op
BenchmarkVIF_DialTLS
Histogram (unit: ms)
Count: 100 Min: 13 Max: 26 Avg: 14.35
------------------------------------------------------------
[ 13, 14) 15 15.0% 15.0% ##
[ 14, 15) 57 57.0% 72.0% ######
[ 15, 16) 24 24.0% 96.0% ##
[ 16, 17) 1 1.0% 97.0%
[ 17, 18) 1 1.0% 98.0%
[ 18, 20) 0 0.0% 98.0%
[ 20, 22) 0 0.0% 98.0%
[ 22, 25) 1 1.0% 99.0%
[ 25, 28) 1 1.0% 100.0%
[ 28, 32) 0 0.0% 100.0%
[ 32, 37) 0 0.0% 100.0%
[ 37, 43) 0 0.0% 100.0%
[ 43, 50) 0 0.0% 100.0%
[ 50, 59) 0 0.0% 100.0%
[ 59, 69) 0 0.0% 100.0%
[ 69, 81) 0 0.0% 100.0%
[ 81, inf) 0 0.0% 100.0%
100 14755394 ns/op
BenchmarkVC_DialTLS
Histogram (unit: ms)
Count: 100 Min: 19 Max: 32 Avg: 19.96
------------------------------------------------------------
[ 19, 20) 53 53.0% 53.0% #####
[ 20, 21) 23 23.0% 76.0% ##
[ 21, 22) 15 15.0% 91.0% ##
[ 22, 23) 6 6.0% 97.0% #
[ 23, 24) 0 0.0% 97.0%
[ 24, 26) 1 1.0% 98.0%
[ 26, 28) 1 1.0% 99.0%
[ 28, 31) 0 0.0% 99.0%
[ 31, 34) 1 1.0% 100.0%
[ 34, 38) 0 0.0% 100.0%
[ 38, 43) 0 0.0% 100.0%
[ 43, 49) 0 0.0% 100.0%
[ 49, 56) 0 0.0% 100.0%
[ 56, 65) 0 0.0% 100.0%
[ 65, 75) 0 0.0% 100.0%
[ 75, 87) 0 0.0% 100.0%
[ 87, inf) 0 0.0% 100.0%
100 20544962 ns/op
Change-Id: I5293af2dc52f1a04478d6ac8fcd8cfc79201abea
diff --git a/lib/testutil/stats.go b/lib/testutil/stats.go
new file mode 100644
index 0000000..976696a
--- /dev/null
+++ b/lib/testutil/stats.go
@@ -0,0 +1,104 @@
+package testutil
+
+import (
+ "bytes"
+ "fmt"
+ "io"
+ "math"
+ "time"
+
+ "veyron.io/veyron/veyron/lib/stats/histogram"
+)
+
+// BenchStats is a simple helper for gathering additional statistics
+// like histogram during benchmarks. This is not thread safe.
+type BenchStats struct {
+ numBuckets int
+ unit time.Duration
+ min, max int64
+ histogram *histogram.Histogram
+
+ durations durationSlice
+ dirty bool
+}
+
+type durationSlice []time.Duration
+
+// NewBenchStats creates a new BenchStats instance. If numBuckets is not
+// positive, the default value (16) will be used.
+func NewBenchStats(numBuckets int) *BenchStats {
+ if numBuckets <= 0 {
+ numBuckets = 16
+ }
+ return &BenchStats{
+ // Use one more bucket for the last unbounded bucket.
+ numBuckets: numBuckets + 1,
+ durations: make(durationSlice, 0, 100000),
+ }
+}
+
+// Add adds an elapsed time per operation to the BenchStats.
+func (stats *BenchStats) Add(d time.Duration) {
+ stats.durations = append(stats.durations, d)
+ stats.dirty = true
+}
+
+// maybeUpdate updates internal stat data if there was any newly added
+// stats since this was updated.
+func (stats *BenchStats) maybeUpdate() {
+ if !stats.dirty || len(stats.durations) == 0 {
+ return
+ }
+
+ stats.min = math.MaxInt64
+ stats.max = 0
+ for _, d := range stats.durations {
+ if stats.min > int64(d) {
+ stats.min = int64(d)
+ }
+ if stats.max < int64(d) {
+ stats.max = int64(d)
+ }
+ }
+
+ // Use the largest unit that can represent the minimum time duration.
+ stats.unit = time.Nanosecond
+ for _, u := range []time.Duration{time.Microsecond, time.Millisecond, time.Second} {
+ if stats.min <= int64(u) {
+ break
+ }
+ stats.unit = u
+ }
+
+ // Adjust the min/max according to the new unit.
+ stats.min /= int64(stats.unit)
+ stats.max /= int64(stats.unit)
+
+ stats.histogram = histogram.New(histogram.Options{
+ NumBuckets: stats.numBuckets,
+ // max(i.e., Nth lower bound) = min + (1 + growthFactor)^(numBuckets-2).
+ GrowthFactor: math.Pow(float64(stats.max-stats.min), 1/float64(stats.numBuckets-2)) - 1,
+ SmallestBucketSize: 1.0,
+ MinValue: stats.min})
+
+ for _, d := range stats.durations {
+ stats.histogram.Add(int64(d / stats.unit))
+ }
+
+ stats.dirty = false
+}
+
+// Print writes textual output of the BenchStats.
+func (stats *BenchStats) Print(w io.Writer) {
+ stats.maybeUpdate()
+
+ fmt.Fprintf(w, "Histogram (unit: %s)\n", fmt.Sprintf("%v", stats.unit)[1:])
+ stats.histogram.Value().Print(w)
+}
+
+// String returns the textual output of the BenchStats as string.
+func (stats *BenchStats) String() string {
+ var b bytes.Buffer
+ stats.Print(&b)
+ return b.String()
+}
diff --git a/runtimes/google/ipc/stream/benchmark/dial_test.go b/runtimes/google/ipc/stream/benchmark/dial_test.go
new file mode 100644
index 0000000..ee87feb
--- /dev/null
+++ b/runtimes/google/ipc/stream/benchmark/dial_test.go
@@ -0,0 +1,10 @@
+package benchmark
+
+import "testing"
+
+func BenchmarkVIF_Dial(b *testing.B) { benchmarkVIFDial(b, securityNone) }
+func BenchmarkVIF_DialTLS(b *testing.B) { benchmarkVIFDial(b, securityTLS) }
+
+// Note: We don't benchmark Non-TLC VC Dial for now since it doesn't wait ack
+// from the server after sending "OpenVC".
+func BenchmarkVC_DialTLS(b *testing.B) { benchmarkVCDial(b, securityTLS) }
diff --git a/runtimes/google/ipc/stream/benchmark/dial_vc.go b/runtimes/google/ipc/stream/benchmark/dial_vc.go
new file mode 100644
index 0000000..e0e397d
--- /dev/null
+++ b/runtimes/google/ipc/stream/benchmark/dial_vc.go
@@ -0,0 +1,58 @@
+package benchmark
+
+import (
+ "fmt"
+ "testing"
+ "time"
+
+ "veyron.io/veyron/veyron/lib/testutil"
+ "veyron.io/veyron/veyron/runtimes/google/ipc/stream/manager"
+
+ "veyron.io/veyron/veyron2/naming"
+ "veyron.io/veyron/veyron2/options"
+)
+
+// benchmarkVCDial measures VC creation time over the underlying VIF.
+func benchmarkVCDial(b *testing.B, mode options.VCSecurityLevel) {
+ stats := testutil.NewBenchStats(16)
+
+ server := manager.InternalNew(naming.FixedRoutingID(0x5))
+ client := manager.InternalNew(naming.FixedRoutingID(0xc))
+
+ _, ep, err := server.Listen("tcp", "127.0.0.1:0", mode)
+ if err != nil {
+ b.Fatal(err)
+ }
+
+ // Warmup to create the underlying VIF.
+ _, err = client.Dial(ep, mode)
+ if err != nil {
+ b.Fatal(err)
+ }
+
+ // Reset the timer to exclude any underlying setup time from measurement.
+ b.ResetTimer()
+
+ for i := 0; i < b.N; i++ {
+ b.StartTimer()
+ start := time.Now()
+
+ _, err := client.Dial(ep, mode)
+ if err != nil {
+ b.Fatal(err)
+ }
+
+ duration := time.Since(start)
+ b.StopTimer()
+
+ stats.Add(duration)
+
+ client.ShutdownEndpoint(ep)
+ }
+
+ client.Shutdown()
+ server.Shutdown()
+
+ fmt.Println()
+ fmt.Println(stats)
+}
diff --git a/runtimes/google/ipc/stream/benchmark/dial_vif.go b/runtimes/google/ipc/stream/benchmark/dial_vif.go
new file mode 100644
index 0000000..40289f2
--- /dev/null
+++ b/runtimes/google/ipc/stream/benchmark/dial_vif.go
@@ -0,0 +1,51 @@
+package benchmark
+
+import (
+ "fmt"
+ "net"
+ "testing"
+ "time"
+
+ "veyron.io/veyron/veyron/lib/testutil"
+ "veyron.io/veyron/veyron/runtimes/google/ipc/stream/vif"
+
+ "veyron.io/veyron/veyron2/naming"
+ "veyron.io/veyron/veyron2/options"
+)
+
+// benchmarkVIFDial measures VIF creation time over the underlying net connection.
+func benchmarkVIFDial(b *testing.B, mode options.VCSecurityLevel) {
+ stats := testutil.NewBenchStats(16)
+
+ // Reset the timer to exclude any underlying setup time from measurement.
+ b.ResetTimer()
+
+ for i := 0; i < b.N; i++ {
+ b.StopTimer()
+ nc, ns := net.Pipe()
+
+ server, err := vif.InternalNewAcceptedVIF(ns, naming.FixedRoutingID(0x5), nil, mode)
+ if err != nil {
+ b.Fatal(err)
+ }
+
+ b.StartTimer()
+ start := time.Now()
+
+ client, err := vif.InternalNewDialedVIF(nc, naming.FixedRoutingID(0xc), nil, mode)
+ if err != nil {
+ b.Fatal(err)
+ }
+
+ duration := time.Since(start)
+ b.StopTimer()
+
+ stats.Add(duration)
+
+ client.Close()
+ server.Close()
+ }
+
+ fmt.Println()
+ fmt.Println(stats)
+}
