Skip to content

Commit

Permalink
feat: add an "ipfs diag profile" command
Browse files Browse the repository at this point in the history
This should replace the "collect-profiles.sh" script and allow users to
easily collect profiles.

At the moment, it just dumps all profiles into a single zip file. It
does this server-side so it's easy fetch them with curl.

In the future, it would be nice to add:

1. Progress indicators (cpu profiles take 30 seconds).
2. An option to specify which profiles to collect.

But we can handle that later.

Unfortunately, this command doesn't produce symbolized svgs as I didn't
want to depend on having a local go compiler.
  • Loading branch information
Stebalien committed Jul 21, 2021
1 parent 050a281 commit d52d183
Show file tree
Hide file tree
Showing 5 changed files with 283 additions and 27 deletions.
5 changes: 3 additions & 2 deletions core/commands/diag.go
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,8 @@ var DiagCmd = &cmds.Command{
},

Subcommands: map[string]*cmds.Command{
"sys": sysDiagCmd,
"cmds": ActiveReqsCmd,
"sys": sysDiagCmd,
"cmds": ActiveReqsCmd,
"profile": sysProfileCmd,
},
}
205 changes: 205 additions & 0 deletions core/commands/profile.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,205 @@
package commands

import (
"archive/zip"
"context"
"encoding/json"
"fmt"
"io"
"os"
"runtime"
"runtime/pprof"
"strings"
"time"

cmds "github.com/ipfs/go-ipfs-cmds"
"github.com/ipfs/go-ipfs/core"
"github.com/ipfs/go-ipfs/core/commands/cmdenv"
"github.com/ipfs/go-ipfs/core/commands/e"
)

// time format that works in filenames on windows.
var timeFormat = strings.ReplaceAll(time.RFC3339, ":", "_")

type profileResult struct {
File string
}

const cpuProfileTimeOption = "cpu-profile-time"

var sysProfileCmd = &cmds.Command{
NoLocal: true,
Options: []cmds.Option{
cmds.StringOption(outputOptionName, "o", "The path where the output should be stored."),
cmds.StringOption(cpuProfileTimeOption, "The amount of time spent profiling CPU usage.").WithDefault("30s"),
},
Run: func(req *cmds.Request, res cmds.ResponseEmitter, env cmds.Environment) error {
cpuProfileTimeStr, _ := req.Options[cpuProfileTimeOption].(string)
cpuProfileTime, err := time.ParseDuration(cpuProfileTimeStr)
if err != nil {
return fmt.Errorf("failed to parse CPU profile duration %q: %w", cpuProfileTimeStr, err)
}

nd, err := cmdenv.GetNode(env)
if err != nil {
return err
}

r, w := io.Pipe()
go func() {
_ = w.CloseWithError(writeProfiles(req.Context, nd, cpuProfileTime, w))
}()
return res.Emit(r)
},
PostRun: cmds.PostRunMap{
cmds.CLI: func(res cmds.Response, re cmds.ResponseEmitter) error {
v, err := res.Next()
if err != nil {
return err
}

outReader, ok := v.(io.Reader)
if !ok {
return e.New(e.TypeErr(outReader, v))
}

outPath, _ := res.Request().Options[outputOptionName].(string)
if outPath == "" {
outPath = "ipfs-profile-" + time.Now().Format(timeFormat) + ".zip"
}
fi, err := os.Create(outPath)
if err != nil {
return err
}
defer fi.Close()

_, err = io.Copy(fi, outReader)
if err != nil {
return err
}
return re.Emit(&profileResult{File: outPath})
},
},
Encoders: cmds.EncoderMap{
cmds.Text: cmds.MakeTypedEncoder(func(req *cmds.Request, w io.Writer, out *profileResult) error {
fmt.Fprintf(w, "Wrote profiles to: %s\n", out.File)
return nil
}),
},
}

func writeProfiles(ctx context.Context, nd *core.IpfsNode, cpuProfileTime time.Duration, w io.Writer) error {
archive := zip.NewWriter(w)

// Take some profiles.
type profile struct {
name string
file string
debug int
}

profiles := []profile{{
name: "goroutine",
file: "goroutines.stacks",
debug: 2,
}, {
name: "goroutine",
file: "goroutines.pprof",
}, {
name: "heap",
file: "heap.pprof",
}}

for _, profile := range profiles {
prof := pprof.Lookup(profile.name)
out, err := archive.Create(profile.file)
if err != nil {
return err
}
err = prof.WriteTo(out, profile.debug)
if err != nil {
return err
}
}

// Take a CPU profile.
if cpuProfileTime != 0 {
out, err := archive.Create("cpu.pprof")
if err != nil {
return err
}

err = writeCPUProfile(ctx, cpuProfileTime, out)
if err != nil {
return err
}
}

// Collect info
{
out, err := archive.Create("sysinfo.json")
if err != nil {
return err
}
info, err := getInfo(nd)
if err != nil {
return err
}
err = json.NewEncoder(out).Encode(info)
if err != nil {
return err
}
}

// Collect binary
if fi, err := openIPFSBinary(); err == nil {
fname := "ipfs"
if runtime.GOOS == "windows" {
fname += ".exe"
}

out, err := archive.Create(fname)
if err != nil {
return err
}

_, err = io.Copy(out, fi)
_ = fi.Close()
if err != nil {
return err
}
}
return archive.Close()
}

func writeCPUProfile(ctx context.Context, d time.Duration, w io.Writer) error {
if err := pprof.StartCPUProfile(w); err != nil {
return err
}
defer pprof.StopCPUProfile()

timer := time.NewTimer(d)
defer timer.Stop()

select {
case <-timer.C:
case <-ctx.Done():
return ctx.Err()
}
return nil
}

func openIPFSBinary() (*os.File, error) {
if runtime.GOOS == "linux" {
pid := os.Getpid()
fi, err := os.Open(fmt.Sprintf("/proc/%d/exe", pid))
if err == nil {
return fi, nil
}
}
path, err := os.Executable()
if err != nil {
return nil, err
}
return os.Open(path)
}
56 changes: 33 additions & 23 deletions core/commands/sysdiag.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ import (
"runtime"

version "github.com/ipfs/go-ipfs"
"github.com/ipfs/go-ipfs/core"
cmdenv "github.com/ipfs/go-ipfs/core/commands/cmdenv"

cmds "github.com/ipfs/go-ipfs-cmds"
Expand All @@ -21,40 +22,49 @@ Prints out information about your computer to aid in easier debugging.
`,
},
Run: func(req *cmds.Request, res cmds.ResponseEmitter, env cmds.Environment) error {
info := make(map[string]interface{})
err := runtimeInfo(info)
nd, err := cmdenv.GetNode(env)
if err != nil {
return err
}

err = envVarInfo(info)
info, err := getInfo(nd)
if err != nil {
return err
}
return cmds.EmitOnce(res, info)
},
}

err = diskSpaceInfo(info)
if err != nil {
return err
}
func getInfo(nd *core.IpfsNode) (map[string]interface{}, error) {
info := make(map[string]interface{})
err := runtimeInfo(info)
if err != nil {
return nil, err
}

err = memInfo(info)
if err != nil {
return err
}
nd, err := cmdenv.GetNode(env)
if err != nil {
return err
}
err = envVarInfo(info)
if err != nil {
return nil, err
}

err = netInfo(nd.IsOnline, info)
if err != nil {
return err
}
err = diskSpaceInfo(info)
if err != nil {
return nil, err
}

info["ipfs_version"] = version.CurrentVersionNumber
info["ipfs_commit"] = version.CurrentCommit
return cmds.EmitOnce(res, info)
},
err = memInfo(info)
if err != nil {
return nil, err
}

err = netInfo(nd.IsOnline, info)
if err != nil {
return nil, err
}

info["ipfs_version"] = version.CurrentVersionNumber
info["ipfs_commit"] = version.CurrentCommit
return info, nil
}

func runtimeInfo(out map[string]interface{}) error {
Expand Down
4 changes: 2 additions & 2 deletions docs/debug-guide.md
Original file line number Diff line number Diff line change
Expand Up @@ -15,8 +15,8 @@ When you see ipfs doing something (using lots of CPU, memory, or otherwise
being weird), the first thing you want to do is gather all the relevant
profiling information.

There's a script (`bin/collect-profiles.sh`) that will do this for you and
bundle the results up into a tarball, ready to be attached to a bug report.
There's a command (`ipfs diag profile`) that will do this for you and
bundle the results up into a zip file, ready to be attached to a bug report.

If you feel intrepid, you can dump this information and investigate it yourself:

Expand Down
40 changes: 40 additions & 0 deletions test/sharness/t0152-profile.sh
Original file line number Diff line number Diff line change
@@ -0,0 +1,40 @@
#!/usr/bin/env bash
#
# Copyright (c) 2016 Jeromy Johnson
# MIT Licensed; see the LICENSE file in this repository.
#

test_description="Test profile collection"

. lib/test-lib.sh

test_init_ipfs

test_expect_success "profiling requires a running daemon" '
test_must_fail ipfs diag profile
'

test_launch_ipfs_daemon

test_expect_success "test profiling" '
ipfs diag profile --cpu-profile-time=1s > cmd_out
'

test_expect_success "filename shows up in output" '
grep -q "ipfs-profile" cmd_out > /dev/null
'

test_expect_success "profile file created" '
test -e "$(sed -n -e "s/.*\(ipfs-profile.*\.zip\)/\1/p" cmd_out)"
'

test_expect_success "test profiling with -o (without CPU profiling)" '
ipfs diag profile --cpu-profile-time=0 -o test-profile.zip
'

test_expect_success "test that test-profile.zip exists" '
test -e test-profile.zip
'

test_kill_ipfs_daemon
test_done

0 comments on commit d52d183

Please sign in to comment.