2019-04-29 21:25:05 +00:00
|
|
|
// Copyright 2018 The gVisor Authors.
|
2018-06-20 20:30:39 +00:00
|
|
|
//
|
|
|
|
// 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 cmd
|
|
|
|
|
|
|
|
import (
|
2018-11-28 22:00:54 +00:00
|
|
|
"context"
|
2019-03-11 18:46:18 +00:00
|
|
|
"os"
|
2021-01-05 21:20:12 +00:00
|
|
|
"os/signal"
|
2019-06-24 22:01:58 +00:00
|
|
|
"strconv"
|
|
|
|
"strings"
|
2020-12-30 00:21:27 +00:00
|
|
|
"sync"
|
2019-03-11 18:46:18 +00:00
|
|
|
"time"
|
2018-08-28 03:35:00 +00:00
|
|
|
|
2018-06-20 20:30:39 +00:00
|
|
|
"github.com/google/subcommands"
|
2021-03-07 06:04:58 +00:00
|
|
|
"golang.org/x/sys/unix"
|
2019-06-13 23:49:09 +00:00
|
|
|
"gvisor.dev/gvisor/pkg/log"
|
2019-06-24 22:01:58 +00:00
|
|
|
"gvisor.dev/gvisor/pkg/sentry/control"
|
2020-08-20 01:35:35 +00:00
|
|
|
"gvisor.dev/gvisor/runsc/config"
|
2019-06-13 23:49:09 +00:00
|
|
|
"gvisor.dev/gvisor/runsc/container"
|
2020-02-10 21:56:17 +00:00
|
|
|
"gvisor.dev/gvisor/runsc/flag"
|
2018-06-20 20:30:39 +00:00
|
|
|
)
|
|
|
|
|
|
|
|
// Debug implements subcommands.Command for the "debug" command.
|
|
|
|
type Debug struct {
|
2020-08-05 18:28:15 +00:00
|
|
|
pid int
|
|
|
|
stacks bool
|
|
|
|
signal int
|
|
|
|
profileHeap string
|
|
|
|
profileCPU string
|
|
|
|
profileBlock string
|
|
|
|
profileMutex string
|
|
|
|
trace string
|
|
|
|
strace string
|
|
|
|
logLevel string
|
|
|
|
logPackets string
|
2021-01-05 21:20:12 +00:00
|
|
|
delay time.Duration
|
2020-08-05 18:28:15 +00:00
|
|
|
duration time.Duration
|
|
|
|
ps bool
|
2018-06-20 20:30:39 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
// Name implements subcommands.Command.
|
|
|
|
func (*Debug) Name() string {
|
|
|
|
return "debug"
|
|
|
|
}
|
|
|
|
|
|
|
|
// Synopsis implements subcommands.Command.
|
|
|
|
func (*Debug) Synopsis() string {
|
|
|
|
return "shows a variety of debug information"
|
|
|
|
}
|
|
|
|
|
|
|
|
// Usage implements subcommands.Command.
|
|
|
|
func (*Debug) Usage() string {
|
|
|
|
return `debug [flags] <container id>`
|
|
|
|
}
|
|
|
|
|
|
|
|
// SetFlags implements subcommands.Command.
|
|
|
|
func (d *Debug) SetFlags(f *flag.FlagSet) {
|
|
|
|
f.IntVar(&d.pid, "pid", 0, "sandbox process ID. Container ID is not necessary if this is set")
|
|
|
|
f.BoolVar(&d.stacks, "stacks", false, "if true, dumps all sandbox stacks to the log")
|
2019-03-11 18:46:18 +00:00
|
|
|
f.StringVar(&d.profileHeap, "profile-heap", "", "writes heap profile to the given file.")
|
|
|
|
f.StringVar(&d.profileCPU, "profile-cpu", "", "writes CPU profile to the given file.")
|
2020-02-25 07:49:08 +00:00
|
|
|
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.")
|
2021-01-05 21:20:12 +00:00
|
|
|
f.DurationVar(&d.delay, "delay", time.Hour, "amount of time to delay for collecting heap and goroutine profiles.")
|
|
|
|
f.DurationVar(&d.duration, "duration", time.Hour, "amount of time to wait for CPU and trace profiles.")
|
2019-05-29 18:30:59 +00:00
|
|
|
f.StringVar(&d.trace, "trace", "", "writes an execution trace to the given file.")
|
2018-08-28 03:35:00 +00:00
|
|
|
f.IntVar(&d.signal, "signal", -1, "sends signal to the sandbox")
|
2020-12-30 00:21:27 +00:00
|
|
|
f.StringVar(&d.strace, "strace", "", `A comma separated list of syscalls to trace. "all" enables all traces, "off" disables all.`)
|
2019-06-24 22:01:58 +00:00
|
|
|
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.")
|
2019-12-11 18:30:43 +00:00
|
|
|
f.BoolVar(&d.ps, "ps", false, "lists processes")
|
2018-06-20 20:30:39 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
// Execute implements subcommands.Command.Execute.
|
|
|
|
func (d *Debug) Execute(_ context.Context, f *flag.FlagSet, args ...interface{}) subcommands.ExitStatus {
|
|
|
|
var c *container.Container
|
2020-08-20 01:35:35 +00:00
|
|
|
conf := args[0].(*config.Config)
|
2018-06-20 20:30:39 +00:00
|
|
|
|
|
|
|
if d.pid == 0 {
|
|
|
|
// No pid, container ID must have been provided.
|
|
|
|
if f.NArg() != 1 {
|
|
|
|
f.Usage()
|
|
|
|
return subcommands.ExitUsageError
|
|
|
|
}
|
2020-12-17 18:44:44 +00:00
|
|
|
id := f.Arg(0)
|
|
|
|
|
2018-06-20 20:30:39 +00:00
|
|
|
var err error
|
2020-12-17 18:44:44 +00:00
|
|
|
c, err = container.Load(conf.RootDir, container.FullID{ContainerID: id}, container.LoadOpts{})
|
2018-06-20 20:30:39 +00:00
|
|
|
if err != nil {
|
2019-06-24 22:01:58 +00:00
|
|
|
return Errorf("loading container %q: %v", f.Arg(0), err)
|
2018-06-20 20:30:39 +00:00
|
|
|
}
|
|
|
|
} else {
|
|
|
|
if f.NArg() != 0 {
|
|
|
|
f.Usage()
|
|
|
|
return subcommands.ExitUsageError
|
|
|
|
}
|
|
|
|
// Go over all sandboxes and find the one that matches PID.
|
|
|
|
ids, err := container.List(conf.RootDir)
|
|
|
|
if err != nil {
|
2019-06-24 22:01:58 +00:00
|
|
|
return Errorf("listing containers: %v", err)
|
2018-06-20 20:30:39 +00:00
|
|
|
}
|
|
|
|
for _, id := range ids {
|
2020-12-17 18:44:44 +00:00
|
|
|
candidate, err := container.Load(conf.RootDir, id, container.LoadOpts{Exact: true, SkipCheck: true})
|
2018-06-20 20:30:39 +00:00
|
|
|
if err != nil {
|
2020-12-17 18:44:44 +00:00
|
|
|
log.Warningf("Skipping container %q: %v", id, err)
|
|
|
|
continue
|
2018-06-20 20:30:39 +00:00
|
|
|
}
|
2018-10-10 04:06:18 +00:00
|
|
|
if candidate.SandboxPid() == d.pid {
|
2018-06-20 20:30:39 +00:00
|
|
|
c = candidate
|
|
|
|
break
|
|
|
|
}
|
|
|
|
}
|
|
|
|
if c == nil {
|
2019-06-24 22:01:58 +00:00
|
|
|
return Errorf("container with PID %d not found", d.pid)
|
2018-06-20 20:30:39 +00:00
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2020-12-30 19:16:12 +00:00
|
|
|
if !c.IsSandboxRunning() {
|
2019-06-24 22:01:58 +00:00
|
|
|
return Errorf("container sandbox is not running")
|
2018-06-20 20:30:39 +00:00
|
|
|
}
|
2018-09-13 23:36:53 +00:00
|
|
|
log.Infof("Found sandbox %q, PID: %d", c.Sandbox.ID, c.Sandbox.Pid)
|
2018-06-20 20:30:39 +00:00
|
|
|
|
2020-12-30 00:21:27 +00:00
|
|
|
// Perform synchronous actions.
|
2018-08-28 03:35:00 +00:00
|
|
|
if d.signal > 0 {
|
|
|
|
log.Infof("Sending signal %d to process: %d", d.signal, c.Sandbox.Pid)
|
2021-03-07 06:04:58 +00:00
|
|
|
if err := unix.Kill(c.Sandbox.Pid, unix.Signal(d.signal)); err != nil {
|
2019-06-24 22:01:58 +00:00
|
|
|
return Errorf("failed to send signal %d to processs %d", d.signal, c.Sandbox.Pid)
|
2018-08-28 03:35:00 +00:00
|
|
|
}
|
|
|
|
}
|
2018-06-20 20:30:39 +00:00
|
|
|
if d.stacks {
|
|
|
|
log.Infof("Retrieving sandbox stacks")
|
|
|
|
stacks, err := c.Sandbox.Stacks()
|
|
|
|
if err != nil {
|
2019-06-24 22:01:58 +00:00
|
|
|
return Errorf("retrieving stacks: %v", err)
|
2018-06-20 20:30:39 +00:00
|
|
|
}
|
|
|
|
log.Infof(" *** Stack dump ***\n%s", stacks)
|
|
|
|
}
|
2019-06-24 22:01:58 +00:00
|
|
|
if d.strace != "" || len(d.logLevel) != 0 || len(d.logPackets) != 0 {
|
|
|
|
args := control.LoggingArgs{}
|
|
|
|
switch strings.ToLower(d.strace) {
|
|
|
|
case "":
|
|
|
|
// strace not set, nothing to do here.
|
|
|
|
|
|
|
|
case "off":
|
|
|
|
log.Infof("Disabling strace")
|
|
|
|
args.SetStrace = true
|
|
|
|
|
|
|
|
case "all":
|
|
|
|
log.Infof("Enabling all straces")
|
|
|
|
args.SetStrace = true
|
|
|
|
args.EnableStrace = true
|
|
|
|
|
|
|
|
default:
|
|
|
|
log.Infof("Enabling strace for syscalls: %s", d.strace)
|
|
|
|
args.SetStrace = true
|
|
|
|
args.EnableStrace = true
|
|
|
|
args.StraceWhitelist = strings.Split(d.strace, ",")
|
|
|
|
}
|
|
|
|
|
|
|
|
if len(d.logLevel) != 0 {
|
|
|
|
args.SetLevel = true
|
|
|
|
switch strings.ToLower(d.logLevel) {
|
|
|
|
case "warning", "0":
|
|
|
|
args.Level = log.Warning
|
|
|
|
case "info", "1":
|
|
|
|
args.Level = log.Info
|
|
|
|
case "debug", "2":
|
|
|
|
args.Level = log.Debug
|
|
|
|
default:
|
|
|
|
return Errorf("invalid log level %q", d.logLevel)
|
|
|
|
}
|
|
|
|
log.Infof("Setting log level %v", args.Level)
|
|
|
|
}
|
|
|
|
|
|
|
|
if len(d.logPackets) != 0 {
|
|
|
|
args.SetLogPackets = true
|
|
|
|
lp, err := strconv.ParseBool(d.logPackets)
|
|
|
|
if err != nil {
|
|
|
|
return Errorf("invalid value for log_packets %q", d.logPackets)
|
|
|
|
}
|
|
|
|
args.LogPackets = lp
|
|
|
|
if args.LogPackets {
|
|
|
|
log.Infof("Enabling packet logging")
|
|
|
|
} else {
|
|
|
|
log.Infof("Disabling packet logging")
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
if err := c.Sandbox.ChangeLogging(args); err != nil {
|
|
|
|
return Errorf(err.Error())
|
|
|
|
}
|
|
|
|
log.Infof("Logging options changed")
|
|
|
|
}
|
2019-12-11 18:30:43 +00:00
|
|
|
if d.ps {
|
|
|
|
pList, err := c.Processes()
|
|
|
|
if err != nil {
|
|
|
|
Fatalf("getting processes for container: %v", err)
|
|
|
|
}
|
|
|
|
o, err := control.ProcessListToJSON(pList)
|
|
|
|
if err != nil {
|
|
|
|
Fatalf("generating JSON: %v", err)
|
|
|
|
}
|
|
|
|
log.Infof(o)
|
|
|
|
}
|
2019-06-24 22:01:58 +00:00
|
|
|
|
2020-12-30 00:21:27 +00:00
|
|
|
// Open profiling files.
|
|
|
|
var (
|
2021-01-05 21:20:12 +00:00
|
|
|
heapFile *os.File
|
2020-12-30 00:21:27 +00:00
|
|
|
cpuFile *os.File
|
|
|
|
traceFile *os.File
|
|
|
|
blockFile *os.File
|
|
|
|
mutexFile *os.File
|
|
|
|
)
|
2021-01-05 21:20:12 +00:00
|
|
|
if d.profileHeap != "" {
|
|
|
|
f, err := os.OpenFile(d.profileHeap, os.O_CREATE|os.O_WRONLY|os.O_TRUNC, 0644)
|
|
|
|
if err != nil {
|
|
|
|
return Errorf("error opening heap profile output: %v", err)
|
|
|
|
}
|
|
|
|
defer f.Close()
|
|
|
|
heapFile = f
|
|
|
|
}
|
2020-12-30 00:21:27 +00:00
|
|
|
if d.profileCPU != "" {
|
2021-01-05 21:20:12 +00:00
|
|
|
f, err := os.OpenFile(d.profileCPU, os.O_CREATE|os.O_WRONLY|os.O_TRUNC, 0644)
|
2020-12-30 00:21:27 +00:00
|
|
|
if err != nil {
|
|
|
|
return Errorf("error opening cpu profile output: %v", err)
|
|
|
|
}
|
|
|
|
defer f.Close()
|
|
|
|
cpuFile = f
|
|
|
|
}
|
|
|
|
if d.trace != "" {
|
2021-01-05 21:20:12 +00:00
|
|
|
f, err := os.OpenFile(d.trace, os.O_CREATE|os.O_WRONLY|os.O_TRUNC, 0644)
|
2020-12-30 00:21:27 +00:00
|
|
|
if err != nil {
|
|
|
|
return Errorf("error opening trace profile output: %v", err)
|
|
|
|
}
|
|
|
|
traceFile = f
|
|
|
|
}
|
|
|
|
if d.profileBlock != "" {
|
2021-01-05 21:20:12 +00:00
|
|
|
f, err := os.OpenFile(d.profileBlock, os.O_CREATE|os.O_WRONLY|os.O_TRUNC, 0644)
|
2020-12-30 00:21:27 +00:00
|
|
|
if err != nil {
|
|
|
|
return Errorf("error opening blocking profile output: %v", err)
|
|
|
|
}
|
|
|
|
defer f.Close()
|
|
|
|
blockFile = f
|
|
|
|
}
|
|
|
|
if d.profileMutex != "" {
|
2021-01-05 21:20:12 +00:00
|
|
|
f, err := os.OpenFile(d.profileMutex, os.O_CREATE|os.O_WRONLY|os.O_TRUNC, 0644)
|
2020-12-30 00:21:27 +00:00
|
|
|
if err != nil {
|
|
|
|
return Errorf("error opening mutex profile output: %v", err)
|
|
|
|
}
|
|
|
|
defer f.Close()
|
|
|
|
mutexFile = f
|
|
|
|
}
|
|
|
|
|
|
|
|
// Collect profiles.
|
|
|
|
var (
|
|
|
|
wg sync.WaitGroup
|
2021-01-05 21:20:12 +00:00
|
|
|
heapErr error
|
2020-12-30 00:21:27 +00:00
|
|
|
cpuErr error
|
|
|
|
traceErr error
|
|
|
|
blockErr error
|
|
|
|
mutexErr error
|
|
|
|
)
|
2021-01-05 21:20:12 +00:00
|
|
|
if heapFile != nil {
|
|
|
|
wg.Add(1)
|
|
|
|
go func() {
|
|
|
|
defer wg.Done()
|
|
|
|
heapErr = c.Sandbox.HeapProfile(heapFile, d.delay)
|
|
|
|
}()
|
|
|
|
}
|
2020-12-30 00:21:27 +00:00
|
|
|
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)
|
|
|
|
}()
|
|
|
|
}
|
|
|
|
|
2021-01-05 21:20:12 +00:00
|
|
|
// Before sleeping, allow us to catch signals and try to exit
|
|
|
|
// gracefully before just exiting. If we can't wait for wg, then
|
|
|
|
// we will not be able to read the errors below safely.
|
|
|
|
readyChan := make(chan struct{})
|
|
|
|
go func() {
|
|
|
|
defer close(readyChan)
|
|
|
|
wg.Wait()
|
|
|
|
}()
|
|
|
|
signals := make(chan os.Signal, 1)
|
2021-03-07 06:04:58 +00:00
|
|
|
signal.Notify(signals, unix.SIGTERM, unix.SIGINT)
|
2021-01-05 21:20:12 +00:00
|
|
|
select {
|
|
|
|
case <-readyChan:
|
|
|
|
break // Safe to proceed.
|
|
|
|
case <-signals:
|
|
|
|
log.Infof("caught signal, waiting at most one more second.")
|
|
|
|
select {
|
|
|
|
case <-signals:
|
|
|
|
log.Infof("caught second signal, exiting immediately.")
|
|
|
|
os.Exit(1) // Not finished.
|
|
|
|
case <-time.After(time.Second):
|
|
|
|
log.Infof("timeout, exiting.")
|
|
|
|
os.Exit(1) // Not finished.
|
|
|
|
case <-readyChan:
|
|
|
|
break // Safe to proceed.
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
// Collect all errors.
|
2020-12-30 00:21:27 +00:00
|
|
|
errorCount := 0
|
2021-01-05 21:20:12 +00:00
|
|
|
if heapErr != nil {
|
|
|
|
errorCount++
|
|
|
|
log.Infof("error collecting heap profile: %v", heapErr)
|
|
|
|
os.Remove(heapFile.Name())
|
|
|
|
}
|
2020-12-30 00:21:27 +00:00
|
|
|
if cpuErr != nil {
|
2021-01-05 21:20:12 +00:00
|
|
|
errorCount++
|
2020-12-30 00:21:27 +00:00
|
|
|
log.Infof("error collecting cpu profile: %v", cpuErr)
|
2021-01-05 21:20:12 +00:00
|
|
|
os.Remove(cpuFile.Name())
|
2020-12-30 00:21:27 +00:00
|
|
|
}
|
|
|
|
if traceErr != nil {
|
2021-01-05 21:20:12 +00:00
|
|
|
errorCount++
|
2020-12-30 00:21:27 +00:00
|
|
|
log.Infof("error collecting trace profile: %v", traceErr)
|
2021-01-05 21:20:12 +00:00
|
|
|
os.Remove(traceFile.Name())
|
2020-12-30 00:21:27 +00:00
|
|
|
}
|
|
|
|
if blockErr != nil {
|
2021-01-05 21:20:12 +00:00
|
|
|
errorCount++
|
2020-12-30 00:21:27 +00:00
|
|
|
log.Infof("error collecting block profile: %v", blockErr)
|
2021-01-05 21:20:12 +00:00
|
|
|
os.Remove(blockFile.Name())
|
2020-12-30 00:21:27 +00:00
|
|
|
}
|
|
|
|
if mutexErr != nil {
|
2021-01-05 21:20:12 +00:00
|
|
|
errorCount++
|
2020-12-30 00:21:27 +00:00
|
|
|
log.Infof("error collecting mutex profile: %v", mutexErr)
|
2021-01-05 21:20:12 +00:00
|
|
|
os.Remove(mutexFile.Name())
|
2020-12-30 00:21:27 +00:00
|
|
|
}
|
2021-01-05 21:20:12 +00:00
|
|
|
|
2020-12-30 00:21:27 +00:00
|
|
|
if errorCount > 0 {
|
|
|
|
return subcommands.ExitFailure
|
2019-05-29 18:30:59 +00:00
|
|
|
}
|
|
|
|
|
2018-06-20 20:30:39 +00:00
|
|
|
return subcommands.ExitSuccess
|
|
|
|
}
|