diff --git a/test/benchmarks/database/BUILD b/test/benchmarks/database/BUILD index b94793322..60dc8ed77 100644 --- a/test/benchmarks/database/BUILD +++ b/test/benchmarks/database/BUILD @@ -21,5 +21,6 @@ benchmark_test( "//pkg/test/dockerutil", "//test/benchmarks/harness", "//test/benchmarks/tools", + "//test/metricsviz", ], ) diff --git a/test/benchmarks/database/redis_test.go b/test/benchmarks/database/redis_test.go index 36498e6c3..f5fa7905f 100644 --- a/test/benchmarks/database/redis_test.go +++ b/test/benchmarks/database/redis_test.go @@ -24,6 +24,7 @@ import ( "gvisor.dev/gvisor/pkg/test/dockerutil" "gvisor.dev/gvisor/test/benchmarks/harness" "gvisor.dev/gvisor/test/benchmarks/tools" + "gvisor.dev/gvisor/test/metricsviz" ) // All possible operations from redis. Note: "ping" will @@ -85,6 +86,7 @@ func doBenchmarkRedis(b *testing.B, ops []string) { }); err != nil { b.Fatalf("failed to start redis server with: %v", err) } + defer metricsviz.FromContainerLogs(ctx, b, server) if out, err := server.WaitForOutput(ctx, "Ready to accept connections", 3*time.Second); err != nil { b.Fatalf("failed to start redis server: %v %s", err, out) diff --git a/test/benchmarks/fs/fsbench/BUILD b/test/benchmarks/fs/fsbench/BUILD index fa3e93af8..0eac523b8 100644 --- a/test/benchmarks/fs/fsbench/BUILD +++ b/test/benchmarks/fs/fsbench/BUILD @@ -18,5 +18,6 @@ go_library( "//pkg/test/dockerutil", "//test/benchmarks/harness", "//test/benchmarks/tools", + "//test/metricsviz", ], ) diff --git a/test/benchmarks/fs/fsbench/fsbench.go b/test/benchmarks/fs/fsbench/fsbench.go index 344188a26..58aba1d79 100644 --- a/test/benchmarks/fs/fsbench/fsbench.go +++ b/test/benchmarks/fs/fsbench/fsbench.go @@ -25,6 +25,7 @@ import ( "gvisor.dev/gvisor/pkg/test/dockerutil" "gvisor.dev/gvisor/test/benchmarks/harness" "gvisor.dev/gvisor/test/benchmarks/tools" + "gvisor.dev/gvisor/test/metricsviz" ) // FSBenchmark represents a set of work to perform within a container that is instrumented with @@ -124,6 +125,7 @@ func RunWithDifferentFilesystems(ctx context.Context, b *testing.B, machine harn if err := container.Spawn(ctx, runOpts, "sleep", "24h"); err != nil { b.Fatalf("run failed with: %v", err) } + defer metricsviz.FromContainerLogs(ctx, b, container) // Ignore safetext/shsprintf linter suggestion. mkdirCmd := fmt.Sprintf("mkdir -p %s", prefix) diff --git a/test/metricsviz/BUILD b/test/metricsviz/BUILD index e26502e71..4803136fd 100644 --- a/test/metricsviz/BUILD +++ b/test/metricsviz/BUILD @@ -7,10 +7,13 @@ package( go_library( name = "metricsviz", + testonly = 1, srcs = ["metricsviz.go"], + visibility = ["//:sandbox"], deps = [ "//pkg/metric", "//pkg/metric:metric_go_proto", + "//pkg/test/dockerutil", "@org_golang_google_protobuf//encoding/protojson:go_default_library", ], ) diff --git a/test/metricsviz/metricsviz.go b/test/metricsviz/metricsviz.go index f08043aef..87dc3a6d9 100644 --- a/test/metricsviz/metricsviz.go +++ b/test/metricsviz/metricsviz.go @@ -16,15 +16,19 @@ package metricsviz import ( + "context" + "errors" "fmt" "hash/adler32" "strconv" "strings" + "testing" "time" "google.golang.org/protobuf/encoding/protojson" "gvisor.dev/gvisor/pkg/metric" mpb "gvisor.dev/gvisor/pkg/metric/metric_go_proto" + "gvisor.dev/gvisor/pkg/test/dockerutil" ) // MetricName is the name of a metric. @@ -71,11 +75,15 @@ type Data struct { data map[MetricAndFields]*TimeSeries } +// ErrNoMetricData is returned when no metrics data is found in logs. +var ErrNoMetricData = errors.New("no metrics data found") + // Parse parses metrics data out of the given logs containing // profiling metrics data. // If `hasPrefix`, only lines prefixed with `metric.MetricsPrefix` // will be parsed. If false, all lines will be parsed, and the // prefix will be stripped if it is found. +// If the log does not contain any metrics data, ErrNoMetricData is returned. func Parse(logs string, hasPrefix bool) (*Data, error) { data := &Data{make(map[MetricAndFields]*TimeSeries)} var header []MetricAndFields @@ -83,10 +91,12 @@ func Parse(logs string, hasPrefix bool) (*Data, error) { h := adler32.New() checkedHash := false var startTime time.Time + metricsLineFound := false for _, line := range strings.Split(logs, "\n") { if hasPrefix && !strings.HasPrefix(line, metric.MetricsPrefix) { continue } + metricsLineFound = true lineData := strings.TrimPrefix(line, metric.MetricsPrefix) // Check for hash match. @@ -181,6 +191,9 @@ func Parse(logs string, hasPrefix bool) (*Data, error) { timeseries.Data = append(timeseries.Data, Point{When: timestamp, Value: value}) } } + if !metricsLineFound { + return nil, ErrNoMetricData + } if startTime.IsZero() { return nil, fmt.Errorf("no start time found in logs") } @@ -192,3 +205,33 @@ func Parse(logs string, hasPrefix bool) (*Data, error) { } return data, nil } + +// FromContainerLogs parses a container's logs and reports metrics data +// found within. +// The container must be stopped or stoppable by the time this is called. +func FromContainerLogs(ctx context.Context, testLike testing.TB, container *dockerutil.Container) { + // If the container is not stopped, stop it. + // This is necessary to flush the profiling metrics logs. + st, err := container.Status(ctx) + if err != nil { + testLike.Fatalf("Failed to get container status: %v", err) + } + if st.Running { + if err := container.Stop(ctx); err != nil { + testLike.Fatalf("Failed to stop container: %v", err) + } + } + // Get the logs. + logs, err := container.Logs(ctx) + if err != nil { + testLike.Fatalf("Failed to get container logs: %v", err) + } + data, err := Parse(logs, true) + if err != nil { + if errors.Is(err, ErrNoMetricData) { + return // No metric data in the logs, so stay quiet. + } + testLike.Fatalf("Failed to parse metrics data: %v", err) + } + testLike.Logf("Metric data successfully parsed (%d timeseries).", len(data.data)) +}