Skip to content

Commit

Permalink
debug: use human readable dates for filenames
Browse files Browse the repository at this point in the history
The unix timestamps that were used make the debug data a little bit more
difficult to consume. By using human readable dates we can easily see
when the profile data was collected.

This commit also improves the test coverage. Two test cases are removed
and the assertions from those cases are moved to TestDebugCommand.

Now TestDebugCommand is able to validate the contents of all files. This
change reduces the test runtime of the command/debug package by almost
50%. It also makes much more strict assertions about the contents by
using gotest.tools/v3/fs.
  • Loading branch information
dnephin committed Aug 6, 2021
1 parent 6e9ddf6 commit 6f5698b
Show file tree
Hide file tree
Showing 2 changed files with 116 additions and 201 deletions.
72 changes: 36 additions & 36 deletions command/debug/debug.go
Original file line number Diff line number Diff line change
Expand Up @@ -85,6 +85,9 @@ type cmd struct {
// validateTiming can be used to skip validation of interval, duration. This
// is primarily useful for testing
validateTiming bool
// timeNow is a shim for testing, it is used to generate the time used in
// file paths.
timeNow func() time.Time
}

// debugIndex is used to manage the summary of all data recorded
Expand All @@ -102,10 +105,16 @@ type debugIndex struct {
Targets []string
}

// timeDateformat is a modified version of time.RFC3339 which replaces colons with
// underscores. This is to make it more convenient to untar these files, because
// tar assumes colons indicate the file is on a remote host, unless --force-local
// is used.
const timeDateFormat = "2006-01-02T15-04-05Z0700"

func (c *cmd) init() {
c.flags = flag.NewFlagSet("", flag.ContinueOnError)

defaultFilename := fmt.Sprintf("consul-debug-%d", time.Now().Unix())
defaultFilename := fmt.Sprintf("consul-debug-%v", time.Now().Format(timeDateFormat))

c.flags.Var((*flags.AppendSliceValue)(&c.capture), "capture",
fmt.Sprintf("One or more types of information to capture. This can be used "+
Expand All @@ -130,6 +139,9 @@ func (c *cmd) init() {
c.help = flags.Usage(help, c.flags)

c.validateTiming = true
c.timeNow = func() time.Time {
return time.Now().UTC()
}
}

func (c *cmd) Run(args []string) int {
Expand Down Expand Up @@ -208,7 +220,7 @@ func (c *cmd) Run(args []string) int {
Duration: c.duration.String(),
Targets: c.capture,
}
if err := writeJSONFile(fmt.Sprintf("%s/index.json", c.output), index); err != nil {
if err := writeJSONFile(filepath.Join(c.output, "index.json"), index); err != nil {
c.UI.Error(fmt.Sprintf("Error creating index document: %v", err))
return 1
}
Expand Down Expand Up @@ -361,43 +373,32 @@ func (c *cmd) captureInterval(ctx context.Context) error {

func captureShortLived(c *cmd) error {
g := new(errgroup.Group)
timestamp := time.Now().Local().Unix()

timestampDir, err := c.createTimestampDir(timestamp)
dir, err := makeTimestampDir(c.output, c.timeNow())
if err != nil {
return err
}
if c.captureTarget(targetProfiles) {
g.Go(func() error {
return c.captureHeap(timestampDir)
return c.captureHeap(dir)
})

g.Go(func() error {
return c.captureGoRoutines(timestampDir)
return c.captureGoRoutines(dir)
})
}
return g.Wait()
}

func (c *cmd) createTimestampDir(timestamp int64) (string, error) {
// Make the directory that will store all captured data
// for this interval
timestampDir := fmt.Sprintf("%s/%d", c.output, timestamp)
err := os.MkdirAll(timestampDir, 0755)
if err != nil {
return "", err
func makeTimestampDir(base string, now time.Time) (string, error) {
dir := filepath.Join(base, now.Format(timeDateFormat))
if err := os.MkdirAll(dir, 0755); err != nil {
return "", fmt.Errorf("failed to create output directory %v: %w", dir, err)
}
return timestampDir, nil
return dir, nil
}

func (c *cmd) captureLongRunning(ctx context.Context) error {
timestamp := time.Now().Local().Unix()

timestampDir, err := c.createTimestampDir(timestamp)
if err != nil {
return err
}

g := new(errgroup.Group)
// Capture a profile/trace with a minimum of 1s
s := c.duration.Seconds()
Expand All @@ -407,26 +408,26 @@ func (c *cmd) captureLongRunning(ctx context.Context) error {
if c.captureTarget(targetProfiles) {
g.Go(func() error {
// use ctx without a timeout to allow the profile to finish sending
return c.captureProfile(ctx, s, timestampDir)
return c.captureProfile(ctx, s)
})

g.Go(func() error {
// use ctx without a timeout to allow the trace to finish sending
return c.captureTrace(ctx, s, timestampDir)
return c.captureTrace(ctx, s)
})
}
if c.captureTarget(targetLogs) {
g.Go(func() error {
ctx, cancel := context.WithTimeout(ctx, c.duration)
defer cancel()
return c.captureLogs(ctx, timestampDir)
return c.captureLogs(ctx)
})
}
if c.captureTarget(targetMetrics) {
g.Go(func() error {
ctx, cancel := context.WithTimeout(ctx, c.duration)
defer cancel()
return c.captureMetrics(ctx, timestampDir)
return c.captureMetrics(ctx)
})
}

Expand All @@ -439,18 +440,18 @@ func (c *cmd) captureGoRoutines(timestampDir string) error {
return fmt.Errorf("failed to collect goroutine profile: %w", err)
}

return ioutil.WriteFile(fmt.Sprintf("%s/goroutine.prof", timestampDir), gr, 0644)
return ioutil.WriteFile(filepath.Join(timestampDir, "goroutine.prof"), gr, 0644)
}

func (c *cmd) captureTrace(ctx context.Context, s float64, timestampDir string) error {
func (c *cmd) captureTrace(ctx context.Context, s float64) error {
prof, err := c.client.Debug().PProf(ctx, "trace", int(s))
if err != nil {
return fmt.Errorf("failed to collect cpu profile: %w", err)
}
defer prof.Close()

r := bufio.NewReader(prof)
fh, err := os.Create(fmt.Sprintf("%s/trace.out", timestampDir))
fh, err := os.Create(filepath.Join(c.output, "trace.out"))
if err != nil {
return err
}
Expand All @@ -459,15 +460,15 @@ func (c *cmd) captureTrace(ctx context.Context, s float64, timestampDir string)
return err
}

func (c *cmd) captureProfile(ctx context.Context, s float64, timestampDir string) error {
func (c *cmd) captureProfile(ctx context.Context, s float64) error {
prof, err := c.client.Debug().PProf(ctx, "profile", int(s))
if err != nil {
return fmt.Errorf("failed to collect cpu profile: %w", err)
}
defer prof.Close()

r := bufio.NewReader(prof)
fh, err := os.Create(fmt.Sprintf("%s/profile.prof", timestampDir))
fh, err := os.Create(filepath.Join(c.output, "profile.prof"))
if err != nil {
return err
}
Expand All @@ -482,17 +483,17 @@ func (c *cmd) captureHeap(timestampDir string) error {
return fmt.Errorf("failed to collect heap profile: %w", err)
}

return ioutil.WriteFile(fmt.Sprintf("%s/heap.prof", timestampDir), heap, 0644)
return ioutil.WriteFile(filepath.Join(timestampDir, "heap.prof"), heap, 0644)
}

func (c *cmd) captureLogs(ctx context.Context, timestampDir string) error {
func (c *cmd) captureLogs(ctx context.Context) error {
logCh, err := c.client.Agent().Monitor("DEBUG", ctx.Done(), nil)
if err != nil {
return err
}

// Create the log file for writing
f, err := os.Create(fmt.Sprintf("%s/%s", timestampDir, "consul.log"))
f, err := os.Create(filepath.Join(c.output, "consul.log"))
if err != nil {
return err
}
Expand All @@ -513,15 +514,14 @@ func (c *cmd) captureLogs(ctx context.Context, timestampDir string) error {
}
}

func (c *cmd) captureMetrics(ctx context.Context, timestampDir string) error {
func (c *cmd) captureMetrics(ctx context.Context) error {
stream, err := c.client.Agent().MetricsStream(ctx)
if err != nil {
return err
}
defer stream.Close()

filename := fmt.Sprintf("%s/%s.json", timestampDir, "metrics")
fh, err := os.Create(filename)
fh, err := os.Create(filepath.Join(c.output, "metrics.json"))
if err != nil {
return fmt.Errorf("failed to create metrics file: %w", err)
}
Expand Down
Loading

0 comments on commit 6f5698b

Please sign in to comment.