Add metricsviz_cli tool to manually create charts from profiling metrics.

This is part of a series of changes to add metric charts in performance
benchmarks.

Comes with a test, which also serves as an end-to-end-ish test of profiling
metric functionality from collection to charting.

Including `metricsviz` in a `go_binary` requires making it non-`testonly`,
which in turn means removing the `dockerutil` dependency, so this uses an
interface to break the dependency on `dockerutil.Container`.

PiperOrigin-RevId: 633394898
This commit is contained in:
Etienne Perot
2024-05-13 18:30:02 -07:00
committed by gVisor bot
parent 1d800dc14b
commit 113cf439b1
6 changed files with 232 additions and 18 deletions
+1 -2
View File
@@ -7,7 +7,6 @@ package(
go_library(
name = "metricsviz",
testonly = 1,
srcs = [
"metricsviz.go",
"metricsviz_groups.go",
@@ -17,7 +16,7 @@ go_library(
deps = [
"//pkg/metric",
"//pkg/metric:metric_go_proto",
"//pkg/test/dockerutil",
"@com_github_docker_docker//api/types:go_default_library",
"@com_github_go_echarts_go_echarts_v2//charts:go_default_library",
"@com_github_go_echarts_go_echarts_v2//components:go_default_library",
"@com_github_go_echarts_go_echarts_v2//opts:go_default_library",
+51 -12
View File
@@ -22,6 +22,7 @@ import (
"fmt"
"hash/adler32"
"os"
"path"
"regexp"
"slices"
"sort"
@@ -30,6 +31,7 @@ import (
"testing"
"time"
"github.com/docker/docker/api/types"
"github.com/go-echarts/go-echarts/v2/charts"
"github.com/go-echarts/go-echarts/v2/components"
"github.com/go-echarts/go-echarts/v2/opts"
@@ -37,7 +39,6 @@ import (
"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.
@@ -438,6 +439,9 @@ func Parse(logs string, hasPrefix bool) (*Data, error) {
if hasPrefix && !strings.HasPrefix(line, metric.MetricsPrefix) {
continue
}
if line == "" {
continue
}
metricsLineFound = true
lineData := strings.TrimPrefix(line, metric.MetricsPrefix)
@@ -561,17 +565,25 @@ func slugify(s string) string {
return s
}
// Container represents a container that can be stopped and from which we can
// get logs.
type Container interface {
Stop(context.Context) error
Status(context.Context) (types.ContainerState, error)
Logs(context.Context) (string, error)
}
// 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) {
func FromContainerLogs(ctx context.Context, testLike testing.TB, container Container) {
FromNamedContainerLogs(ctx, testLike, container, "")
}
// FromNamedContainerLogs parses a container's logs and reports metrics data
// found within, making note of the container's name on the results page.
// The container must be stopped or stoppable by the time this is called.
func FromNamedContainerLogs(ctx context.Context, testLike testing.TB, container *dockerutil.Container, containerName string) {
func FromNamedContainerLogs(ctx context.Context, testLike testing.TB, container Container, containerName string) {
// If the container is not stopped, stop it.
// This is necessary to flush the profiling metrics logs.
st, err := container.Status(ctx)
@@ -604,7 +616,7 @@ func FromNamedContainerLogs(ctx context.Context, testLike testing.TB, container
if err != nil {
testLike.Fatalf("Failed to generate HTML: %v", err)
}
if err := publishHTMLFn(ctx, testLike, htmlOptions, html); err != nil {
if err := publishHTMLFn(ctx, testLike.Logf, htmlOptions, html); err != nil {
testLike.Fatalf("Failed to publish HTML: %v", err)
}
}
@@ -612,24 +624,50 @@ func FromNamedContainerLogs(ctx context.Context, testLike testing.TB, container
// FromProfilingMetricsLogFile parses a profiling metrics log file
// (as created by --profiling-metrics-log) and reports metrics data within.
func FromProfilingMetricsLogFile(ctx context.Context, testLike testing.TB, logFile string) {
if err := fromFile(ctx, testLike.Name(), logFile, false, testLike.Logf); err != nil {
testLike.Fatalf("Failed to process metrics logs file: %v", err)
}
}
// FromFile reads a file and detects whether it is a profiling metrics log
// file or a file with GVISOR_METRICS-prefixed lines.
// Either way, it parses the metrics data and reports it.
func FromFile(ctx context.Context, logFile string, logFn func(string, ...any)) error {
contents, err := os.ReadFile(logFile)
if err != nil {
testLike.Fatalf("Failed to read log file: %v", err)
return fmt.Errorf("failed to read log file: %w", err)
}
data, err := Parse(string(contents), false)
logName := strings.TrimSuffix(path.Base(logFile), ".log")
for _, line := range strings.Split(string(contents), "\n") {
if strings.HasPrefix(line, metric.MetricsPrefix) {
return fromFile(ctx, logName, logFile, true, logFn)
}
if strings.HasPrefix(line, metric.TimeColumn) {
return fromFile(ctx, logName, logFile, false, logFn)
}
}
return fmt.Errorf("could not recognize %q as a metrics log file", logFile)
}
func fromFile(ctx context.Context, name, logFile string, hasPrefix bool, logFn func(string, ...any)) error {
contents, err := os.ReadFile(logFile)
if err != nil {
return fmt.Errorf("failed to read log file: %w", err)
}
data, err := Parse(string(contents), hasPrefix)
if err != nil {
if errors.Is(err, ErrNoMetricData) {
return // No metric data in the logs, so stay quiet.
return nil // No metric data in the logs, so stay quiet.
}
testLike.Fatalf("Failed to parse metrics data: %v", err)
return fmt.Errorf("failed to parse metrics data: %w", err)
}
htmlOptions := HTMLOptions{
Title: testLike.Name(),
Title: name,
When: data.startTime,
}
html, err := data.ToHTML(htmlOptions)
if err != nil {
testLike.Fatalf("Failed to generate HTML: %v", err)
return fmt.Errorf("failed to generate HTML: %w", err)
}
if strings.HasSuffix(logFile, ".log") {
// Best-effort conversion to HTML next to the .log file in the directory,
@@ -637,7 +675,8 @@ func FromProfilingMetricsLogFile(ctx context.Context, testLike testing.TB, logFi
// publishing step later on.
_ = os.WriteFile(strings.TrimSuffix(logFile, ".log")+".html", []byte(html), 0644)
}
if err := publishHTMLFn(ctx, testLike, htmlOptions, html); err != nil {
testLike.Fatalf("Failed to publish HTML: %v", err)
if err := publishHTMLFn(ctx, logFn, htmlOptions, html); err != nil {
return fmt.Errorf("failed to publish HTML: %w", err)
}
return nil
}
+23
View File
@@ -0,0 +1,23 @@
load("//tools:defs.bzl", "go_binary")
package(
default_applicable_licenses = ["//:license"],
licenses = ["notice"],
)
go_binary(
name = "metricsviz_cli",
srcs = ["metricsviz_cli.go"],
deps = ["//test/metricsviz"],
)
go_test(
name = "metricsviz_cli_test",
srcs = ["metricsviz_cli_test.go"],
data = [":metricsviz_cli"],
deps = [
"//pkg/metric",
"//pkg/test/testutil",
"//test/metricsviz",
],
)
@@ -0,0 +1,40 @@
// Copyright 2024 The gVisor Authors.
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
// metricsviz_cli visualizes metrics from profiling metrics logs.
package main
import (
"context"
"fmt"
"os"
"gvisor.dev/gvisor/test/metricsviz"
)
func main() {
ctx := context.Background()
if len(os.Args) < 2 {
fmt.Fprintf(os.Stderr, "Usage: %s /path/to/profiling_metrics.log\n", os.Args[0])
os.Exit(2)
}
for _, arg := range os.Args[1:] {
if err := metricsviz.FromFile(ctx, arg, func(format string, args ...any) {
fmt.Fprintf(os.Stdout, format+"\n", args...)
}); err != nil {
fmt.Fprintln(os.Stderr, err)
os.Exit(1)
}
}
}
@@ -0,0 +1,114 @@
// Copyright 2024 The gVisor Authors.
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
// Package metricsviz_cli_test tests metricsviz_cli.
package metricsviz_cli_test
import (
"context"
"fmt"
"math/rand/v2"
"os"
"os/exec"
"path"
"strings"
"testing"
"time"
"gvisor.dev/gvisor/pkg/metric"
"gvisor.dev/gvisor/pkg/test/testutil"
"gvisor.dev/gvisor/test/metricsviz"
)
func TestMetricsvizCLI(t *testing.T) {
ctx := context.Background()
cliPath, err := testutil.FindFile("test/metricsviz/metricsviz_cli/metricsviz_cli")
if err != nil {
t.Fatalf("Failed to find metricsviz_cli: %v", err)
}
const testMetricName = "/metricsviz_cli_test/counter"
testMetric := metric.MustCreateNewUint64Metric(testMetricName, true, fmt.Sprintf("test counter for %s", t.Name()))
if err := metric.Initialize(); err != nil {
t.Fatalf("Failed to initialize metrics: %v", err)
}
tempDir := t.TempDir()
for _, lossy := range []bool{true, false} {
t.Run(fmt.Sprintf("lossy=%v", lossy), func(t *testing.T) {
logFilePath := path.Join(tempDir, fmt.Sprintf("lossy=%v.log", lossy))
logFile, err := os.Create(logFilePath)
if err != nil {
t.Fatalf("Failed to create log file %q: %v", logFilePath, err)
}
err = metric.StartProfilingMetrics(metric.ProfilingMetricsOptions[*os.File]{
Sink: logFile,
Lossy: lossy,
Metrics: testMetricName,
Rate: time.Millisecond,
})
if err != nil {
t.Fatalf("Failed to start profiling metrics: %v", err)
}
// Generate some counter increments for 25ms.
waitCtx, waitCancel := context.WithTimeout(ctx, 25*time.Millisecond)
defer waitCancel()
for waitCtx.Err() == nil {
testMetric.Increment()
select {
case <-waitCtx.Done():
case <-time.After(time.Millisecond):
if lossy {
// Also inject some crap in the logs to verify that it can deal
// with text being written in the middle of metrics data.
randomLogs := [][]byte{
[]byte("some log"),
[]byte("some log with a newline\n"),
[]byte("a log with\rcarriage return in the middle"),
[]byte("a log with\nmultiple\nnewlines"),
[]byte{0x01, 0x02, 0x00, 0x03}, // Non-ASCII bytes.
}
if _, err := logFile.Write(randomLogs[rand.IntN(len(randomLogs))]); err != nil {
t.Fatalf("Failed to write random log: %v", err)
}
}
}
}
metric.StopProfilingMetrics()
logFileContents, err := os.ReadFile(logFilePath)
if err != nil {
t.Fatalf("Failed to read log file %q: %v", logFilePath, err)
}
if len(logFileContents) == 0 {
t.Fatalf("Log file %q is empty", logFilePath)
}
t.Logf("Log file %q contents:\n%s\n(end of log file contents)", logFilePath, string(logFileContents))
if output, err := exec.CommandContext(ctx, cliPath, logFilePath).CombinedOutput(); err != nil {
t.Fatalf("Failed to run metricsviz_cli: %v (output: %s)", err, strings.TrimSpace(string(output)))
}
if err = metricsviz.FromFile(ctx, logFilePath, t.Logf); err != nil {
t.Fatalf("Failed to generate metricsviz from %q: %v", logFilePath, err)
}
expectedHTMLPath := path.Join(tempDir, fmt.Sprintf("lossy=%v.html", lossy))
htmlStat, err := os.Stat(expectedHTMLPath)
if err != nil {
t.Fatalf("Failed to stat %q: %v", expectedHTMLPath, err)
}
if htmlStat.Size() == 0 {
t.Fatalf("HTML file %q is empty", expectedHTMLPath)
}
})
}
}
+3 -4
View File
@@ -20,7 +20,6 @@ import (
"os"
"path/filepath"
"strings"
"testing"
"time"
)
@@ -30,7 +29,7 @@ var publishHTMLFn = publishHTML
// publishHTML publishes the HTML contents to a sane file location and
// writes the path to the logger.
func publishHTML(ctx context.Context, testLike testing.TB, htmlOptions HTMLOptions, html string) error {
func publishHTML(ctx context.Context, logFn func(format string, args ...any), htmlOptions HTMLOptions, html string) error {
// We don't use the test's temporary directory here because it is deleted at
// the end of the test, but we want to keep the HTML around later for
// viewing. So we just use a new temporary directory in `/tmp` here.
@@ -55,9 +54,9 @@ func publishHTML(ctx context.Context, testLike testing.TB, htmlOptions HTMLOptio
return fmt.Errorf("failed to chmod %q: %w", htmlPath, err)
}
if htmlOptions.ContainerName == "" {
testLike.Logf("******** METRICS CHARTS: file://%s ********", htmlPath)
logFn("******** METRICS CHARTS: file://%s ********", htmlPath)
} else {
testLike.Logf("******** METRICS CHARTS (%s): file://%s ********", htmlOptions.ContainerName, htmlPath)
logFn("******** METRICS CHARTS (%s): file://%s ********", htmlOptions.ContainerName, htmlPath)
}
return nil
}