From 792cbc06de41f226f76f55a828dfcfad9b8fb16e Mon Sep 17 00:00:00 2001
From: Zach Koopmans <zkoopmans@google.com>
Date: Tue, 10 Nov 2020 21:18:57 -0800
Subject: Add debug logs to startup benchmark.

PiperOrigin-RevId: 341757694
---
 test/benchmarks/base/startup_test.go | 7 +++++++
 test/benchmarks/harness/harness.go   | 3 ++-
 test/benchmarks/harness/util.go      | 9 +++++++++
 3 files changed, 18 insertions(+), 1 deletion(-)

(limited to 'test')

diff --git a/test/benchmarks/base/startup_test.go b/test/benchmarks/base/startup_test.go
index 28731f97a..8ef9f99c4 100644
--- a/test/benchmarks/base/startup_test.go
+++ b/test/benchmarks/base/startup_test.go
@@ -37,6 +37,7 @@ func BenchmarkStartupEmpty(b *testing.B) {
 
 	ctx := context.Background()
 	for i := 0; i < b.N; i++ {
+		harness.DebugLog(b, "Running container: %d", i)
 		container := machine.GetContainer(ctx, b)
 		defer container.CleanUp(ctx)
 		if _, err := container.Run(ctx, dockerutil.RunOpts{
@@ -44,6 +45,7 @@ func BenchmarkStartupEmpty(b *testing.B) {
 		}, "true"); err != nil {
 			b.Fatalf("failed to run container: %v", err)
 		}
+		harness.DebugLog(b, "Ran container: %d", i)
 	}
 }
 
@@ -104,6 +106,7 @@ func BenchmarkStartupNode(b *testing.B) {
 func runServerWorkload(ctx context.Context, b *testing.B, args base.ServerArgs) {
 	b.ResetTimer()
 	for i := 0; i < b.N; i++ {
+		harness.DebugLog(b, "Running iteration: %d", i)
 		if err := func() error {
 			server := args.Machine.GetContainer(ctx, b)
 			defer func() {
@@ -112,15 +115,18 @@ func runServerWorkload(ctx context.Context, b *testing.B, args base.ServerArgs)
 				server.CleanUp(ctx)
 				b.StartTimer()
 			}()
+			harness.DebugLog(b, "Spawning container: %s", args.RunOpts.Image)
 			if err := server.Spawn(ctx, args.RunOpts, args.Cmd...); err != nil {
 				return fmt.Errorf("failed to spawn node instance: %v", err)
 			}
 
+			harness.DebugLog(b, "Finding Container IP")
 			servingIP, err := server.FindIP(ctx, false)
 			if err != nil {
 				return fmt.Errorf("failed to get ip from server: %v", err)
 			}
 
+			harness.DebugLog(b, "Waiting for container to start.")
 			// Wait until the Client sees the server as up.
 			if err := harness.WaitUntilServing(ctx, args.Machine, servingIP, args.Port); err != nil {
 				return fmt.Errorf("failed to wait for serving: %v", err)
@@ -129,6 +135,7 @@ func runServerWorkload(ctx context.Context, b *testing.B, args base.ServerArgs)
 		}(); err != nil {
 			b.Fatal(err)
 		}
+		harness.DebugLog(b, "Ran iteration: %d", i)
 	}
 }
 
diff --git a/test/benchmarks/harness/harness.go b/test/benchmarks/harness/harness.go
index e14cce987..5c9d0e01e 100644
--- a/test/benchmarks/harness/harness.go
+++ b/test/benchmarks/harness/harness.go
@@ -24,7 +24,8 @@ import (
 )
 
 var (
-	help = flag.Bool("help", false, "print this usage message")
+	help  = flag.Bool("help", false, "print this usage message")
+	debug = flag.Bool("debug", false, "turns on debug messages for individual benchmarks")
 )
 
 // Harness is a handle for managing state in benchmark runs.
diff --git a/test/benchmarks/harness/util.go b/test/benchmarks/harness/util.go
index 86b863f78..aeac7ebff 100644
--- a/test/benchmarks/harness/util.go
+++ b/test/benchmarks/harness/util.go
@@ -18,6 +18,7 @@ import (
 	"context"
 	"fmt"
 	"net"
+	"testing"
 
 	"gvisor.dev/gvisor/pkg/test/dockerutil"
 	"gvisor.dev/gvisor/pkg/test/testutil"
@@ -46,3 +47,11 @@ func DropCaches(machine Machine) error {
 	}
 	return nil
 }
+
+// DebugLog prints debug messages if the debug flag is set.
+func DebugLog(b *testing.B, msg string, args ...interface{}) {
+	b.Helper()
+	if *debug {
+		b.Logf(msg, args...)
+	}
+}
-- 
cgit v1.2.3