From c1661e7c84e8747b545db2461e9bc8a0169714f4 Mon Sep 17 00:00:00 2001 From: Etienne Perot Date: Mon, 10 Jun 2024 21:59:08 -0700 Subject: [PATCH] Provide more helpful error messages when profiling is misconfigured. This forwards the output of `runsc debug` to stderr if it fails during a container run. Additionally, for runs with profiling enabled, it checks the runtime arguments and prints an error if the `--profile` flag is not found in it. Profiling is also disabled by default on benchmarks now. This forces the user to be explicit about where benchmarks are stored, which is less confusing than the current behavior of empty output with no explanation as to where the profiles are. Fixes #10433 PiperOrigin-RevId: 642132089 --- Makefile | 3 ++- pkg/test/dockerutil/dockerutil.go | 26 +++++++++++++++++++ pkg/test/dockerutil/profile.go | 43 ++++++++++++++++++++++++++----- 3 files changed, 64 insertions(+), 8 deletions(-) diff --git a/Makefile b/Makefile index 4e4b83d17..401874da7 100644 --- a/Makefile +++ b/Makefile @@ -458,7 +458,8 @@ BENCHMARKS_RUNC ?= true BENCHMARKS_FILTER ?= . BENCHMARKS_OPTIONS ?= -test.benchtime=30s BENCHMARKS_ARGS ?= -test.v -test.bench=$(BENCHMARKS_FILTER) $(BENCHMARKS_OPTIONS) -BENCHMARKS_PROFILE ?= -pprof-dir=/tmp/profile -pprof-cpu -pprof-heap -pprof-block -pprof-mutex +BENCHMARKS_PROFILE ?= +# Example: BENCHMARKS_PROFILE='-pprof-dir=/tmp/profile -pprof-cpu -pprof-heap -pprof-block -pprof-mutex' init-benchmark-table: ## Initializes a BigQuery table with the benchmark schema. @$(call run,//tools/parsers:parser,init --project=$(BENCHMARKS_PROJECT) --dataset=$(BENCHMARKS_DATASET) --table=$(BENCHMARKS_TABLE)) diff --git a/pkg/test/dockerutil/dockerutil.go b/pkg/test/dockerutil/dockerutil.go index c8710e786..5e08a13bc 100644 --- a/pkg/test/dockerutil/dockerutil.go +++ b/pkg/test/dockerutil/dockerutil.go @@ -124,6 +124,32 @@ func RuntimePath() (string, error) { return p, nil } +// RuntimeArgs returns the arguments for the current runtime. +func RuntimeArgs() ([]string, error) { + rs, err := runtimeMap() + if err != nil { + return nil, err + } + argsAny, ok := rs["runtimeArgs"] + if !ok { + // The runtime does not have any arguments. + return nil, nil + } + argsAnySlice, ok := argsAny.([]any) + if !ok { + return nil, fmt.Errorf("runtime arguments should be a list of strings, got: %q (type: %T)", argsAny, argsAny) + } + args := make([]string, 0, len(argsAnySlice)) + for i, argAny := range argsAnySlice { + arg, ok := argAny.(string) + if !ok { + return nil, fmt.Errorf("runtime arguments should be a list of strings, got: %q (index %d is %q which has unexpected type %T)", argsAny, i, argAny, argAny) + } + args = append(args, arg) + } + return args, nil +} + // IsGVisorRuntime returns whether the default container runtime used by // `dockerutil` is gVisor-based or not. func IsGVisorRuntime(ctx context.Context, t *testing.T) (bool, error) { diff --git a/pkg/test/dockerutil/profile.go b/pkg/test/dockerutil/profile.go index 2cb3a54c7..cdf58ceaf 100644 --- a/pkg/test/dockerutil/profile.go +++ b/pkg/test/dockerutil/profile.go @@ -15,11 +15,14 @@ package dockerutil import ( + "bytes" "context" + "errors" "fmt" "os" "os/exec" "path/filepath" + "slices" "time" "golang.org/x/sys/unix" @@ -32,10 +35,12 @@ import ( // profile is for running profiles with 'runsc debug'. type profile struct { - BasePath string - Types []string - Duration time.Duration - cmd *exec.Cmd + BasePath string + Types []string + Duration time.Duration + errorBuf bytes.Buffer + isProfiling bool + cmd *exec.Cmd } // profileInit initializes a profile object, if required. @@ -86,13 +91,15 @@ func (p *profile) createProcess(c *Container) error { return fmt.Errorf("failed to get root directory: %v", err) } - // Format is `runsc --root=rootDir debug --profile-*=file --duration=24h containerID`. - args := []string{fmt.Sprintf("--root=%s", rootDir), "debug"} + // Format is `runsc --debug-log=/dev/stderr --root=rootDir debug --profile-*=file --duration=24h containerID`. + args := []string{"--debug-log=/dev/stderr", fmt.Sprintf("--root=%s", rootDir), "debug"} for _, profileArg := range p.Types { + p.isProfiling = true outputPath := filepath.Join(p.BasePath, fmt.Sprintf("%s.pprof", profileArg)) args = append(args, fmt.Sprintf("--profile-%s=%s", profileArg, outputPath)) } if *trace { + p.isProfiling = true args = append(args, fmt.Sprintf("--trace=%s", filepath.Join(p.BasePath, "sentry.trace"))) } args = append(args, fmt.Sprintf("--duration=%s", p.Duration)) // Or until container exits. @@ -109,7 +116,7 @@ func (p *profile) createProcess(c *Container) error { time.Sleep(100 * time.Millisecond) } p.cmd = exec.Command(path, args...) - p.cmd.Stderr = os.Stderr // Pass through errors. + p.cmd.Stderr = &p.errorBuf if err := p.cmd.Start(); err != nil { return fmt.Errorf("start process failed: %v", err) } @@ -143,6 +150,28 @@ func (p *profile) Start(c *Container) error { func (p *profile) Stop(c *Container) error { killErr := p.killProcess() waitErr := p.waitProcess() + if waitErr != nil || killErr != nil { + if output := p.errorBuf.String(); output != "" { + fmt.Fprintf(os.Stderr, "\nprofile subcommand output:\n%s\n", output) + p.errorBuf.Reset() + } + if p.isProfiling { + runtimeArgs, err := RuntimeArgs() + if err != nil { + return fmt.Errorf("profiling failed (%v / %v) and we failed to get runtime args (%v); perhaps the runtime is not configured for profiling", killErr, waitErr, err) + } + profileEnabled := false + for _, possibleFlag := range []string{"-profile", "--profile", "-profile=true", "--profile=true"} { + if slices.Contains(runtimeArgs, possibleFlag) { + profileEnabled = true + break + } + } + if !profileEnabled { + return errors.New("runtime does not have profiling enabled, profiling will not work; either disable profiling (e.g. BENCHMARKS_PROFILE='') or add --profile=true to runtime flags") + } + } + } if waitErr != nil && killErr != nil { return killErr }