diff options
author | Adin Scannell <ascannell@google.com> | 2020-12-29 16:21:27 -0800 |
---|---|---|
committer | gVisor bot <gvisor-bot@google.com> | 2020-12-29 16:23:01 -0800 |
commit | 85c1c3ed4b8d32c499c53917765acef20cb16248 (patch) | |
tree | 570a3b4a57b970d2fd05b6767f9b1aa0fe6bc393 /runsc/cmd | |
parent | 91c05c609e4dbdc9790037e2dea3e55e784e4da5 (diff) |
Make profiling commands synchronous.
This allows for a model of profiling when you can start collection, and
it will terminate when the sandbox terminates. Without this synchronous
call, it is effectively impossible to collect length blocking and mutex
profiles.
PiperOrigin-RevId: 349483418
Diffstat (limited to 'runsc/cmd')
-rw-r--r-- | runsc/cmd/debug.go | 171 |
1 files changed, 99 insertions, 72 deletions
diff --git a/runsc/cmd/debug.go b/runsc/cmd/debug.go index 1e5a7471a..195a32ac1 100644 --- a/runsc/cmd/debug.go +++ b/runsc/cmd/debug.go @@ -19,6 +19,7 @@ import ( "os" "strconv" "strings" + "sync" "syscall" "time" @@ -70,10 +71,10 @@ func (d *Debug) SetFlags(f *flag.FlagSet) { f.StringVar(&d.profileCPU, "profile-cpu", "", "writes CPU profile to the given file.") f.StringVar(&d.profileBlock, "profile-block", "", "writes block profile to the given file.") f.StringVar(&d.profileMutex, "profile-mutex", "", "writes mutex profile to the given file.") - f.DurationVar(&d.duration, "duration", time.Second, "amount of time to wait for CPU and trace profiles") + f.DurationVar(&d.duration, "duration", time.Second, "amount of time to wait for CPU and trace profiles.") f.StringVar(&d.trace, "trace", "", "writes an execution trace to the given file.") f.IntVar(&d.signal, "signal", -1, "sends signal to the sandbox") - f.StringVar(&d.strace, "strace", "", `A comma separated list of syscalls to trace. "all" enables all traces, "off" disables all`) + f.StringVar(&d.strace, "strace", "", `A comma separated list of syscalls to trace. "all" enables all traces, "off" disables all.`) f.StringVar(&d.logLevel, "log-level", "", "The log level to set: warning (0), info (1), or debug (2).") f.StringVar(&d.logPackets, "log-packets", "", "A boolean value to enable or disable packet logging: true or false.") f.BoolVar(&d.ps, "ps", false, "lists processes") @@ -128,6 +129,7 @@ func (d *Debug) Execute(_ context.Context, f *flag.FlagSet, args ...interface{}) } log.Infof("Found sandbox %q, PID: %d", c.Sandbox.ID, c.Sandbox.Pid) + // Perform synchronous actions. if d.signal > 0 { log.Infof("Sending signal %d to process: %d", d.signal, c.Sandbox.Pid) if err := syscall.Kill(c.Sandbox.Pid, syscall.Signal(d.signal)); err != nil { @@ -143,80 +145,15 @@ func (d *Debug) Execute(_ context.Context, f *flag.FlagSet, args ...interface{}) log.Infof(" *** Stack dump ***\n%s", stacks) } if d.profileHeap != "" { - f, err := os.Create(d.profileHeap) + f, err := os.OpenFile(d.profileHeap, os.O_CREATE|os.O_TRUNC, 0644) if err != nil { - return Errorf(err.Error()) + return Errorf("error opening heap profile output: %v", err) } defer f.Close() - if err := c.Sandbox.HeapProfile(f); err != nil { - return Errorf(err.Error()) - } - log.Infof("Heap profile written to %q", d.profileHeap) - } - if d.profileBlock != "" { - f, err := os.Create(d.profileBlock) - if err != nil { - return Errorf(err.Error()) - } - defer f.Close() - - if err := c.Sandbox.BlockProfile(f); err != nil { - return Errorf(err.Error()) - } - log.Infof("Block profile written to %q", d.profileBlock) - } - if d.profileMutex != "" { - f, err := os.Create(d.profileMutex) - if err != nil { - return Errorf(err.Error()) - } - defer f.Close() - - if err := c.Sandbox.MutexProfile(f); err != nil { - return Errorf(err.Error()) - } - log.Infof("Mutex profile written to %q", d.profileMutex) - } - - delay := false - if d.profileCPU != "" { - delay = true - f, err := os.Create(d.profileCPU) - if err != nil { - return Errorf(err.Error()) - } - defer func() { - f.Close() - if err := c.Sandbox.StopCPUProfile(); err != nil { - Fatalf(err.Error()) - } - log.Infof("CPU profile written to %q", d.profileCPU) - }() - if err := c.Sandbox.StartCPUProfile(f); err != nil { - return Errorf(err.Error()) - } - log.Infof("CPU profile started for %v, writing to %q", d.duration, d.profileCPU) - } - if d.trace != "" { - delay = true - f, err := os.Create(d.trace) - if err != nil { - return Errorf(err.Error()) - } - defer func() { - f.Close() - if err := c.Sandbox.StopTrace(); err != nil { - Fatalf(err.Error()) - } - log.Infof("Trace written to %q", d.trace) - }() - if err := c.Sandbox.StartTrace(f); err != nil { - return Errorf(err.Error()) + return Errorf("error collecting heap profile: %v", err) } - log.Infof("Tracing started for %v, writing to %q", d.duration, d.trace) } - if d.strace != "" || len(d.logLevel) != 0 || len(d.logPackets) != 0 { args := control.LoggingArgs{} switch strings.ToLower(d.strace) { @@ -285,8 +222,98 @@ func (d *Debug) Execute(_ context.Context, f *flag.FlagSet, args ...interface{}) log.Infof(o) } - if delay { - time.Sleep(d.duration) + // Open profiling files. + var ( + cpuFile *os.File + traceFile *os.File + blockFile *os.File + mutexFile *os.File + ) + if d.profileCPU != "" { + f, err := os.OpenFile(d.profileCPU, os.O_CREATE|os.O_TRUNC, 0644) + if err != nil { + return Errorf("error opening cpu profile output: %v", err) + } + defer f.Close() + cpuFile = f + } + if d.trace != "" { + f, err := os.OpenFile(d.trace, os.O_CREATE|os.O_TRUNC, 0644) + if err != nil { + return Errorf("error opening trace profile output: %v", err) + } + traceFile = f + } + if d.profileBlock != "" { + f, err := os.OpenFile(d.profileBlock, os.O_CREATE|os.O_TRUNC, 0644) + if err != nil { + return Errorf("error opening blocking profile output: %v", err) + } + defer f.Close() + blockFile = f + } + if d.profileMutex != "" { + f, err := os.OpenFile(d.profileMutex, os.O_CREATE|os.O_TRUNC, 0644) + if err != nil { + return Errorf("error opening mutex profile output: %v", err) + } + defer f.Close() + mutexFile = f + } + + // Collect profiles. + var ( + wg sync.WaitGroup + cpuErr error + traceErr error + blockErr error + mutexErr error + ) + if cpuFile != nil { + wg.Add(1) + go func() { + defer wg.Done() + cpuErr = c.Sandbox.CPUProfile(cpuFile, d.duration) + }() + } + if traceFile != nil { + wg.Add(1) + go func() { + defer wg.Done() + traceErr = c.Sandbox.Trace(traceFile, d.duration) + }() + } + if blockFile != nil { + wg.Add(1) + go func() { + defer wg.Done() + blockErr = c.Sandbox.BlockProfile(blockFile, d.duration) + }() + } + if mutexFile != nil { + wg.Add(1) + go func() { + defer wg.Done() + mutexErr = c.Sandbox.MutexProfile(mutexFile, d.duration) + }() + } + + wg.Wait() + errorCount := 0 + if cpuErr != nil { + log.Infof("error collecting cpu profile: %v", cpuErr) + } + if traceErr != nil { + log.Infof("error collecting trace profile: %v", traceErr) + } + if blockErr != nil { + log.Infof("error collecting block profile: %v", blockErr) + } + if mutexErr != nil { + log.Infof("error collecting mutex profile: %v", mutexErr) + } + if errorCount > 0 { + return subcommands.ExitFailure } return subcommands.ExitSuccess |