Skip to content

Commit

Permalink
Merge pull request #8291 from ipfs/feat/diag-profile
Browse files Browse the repository at this point in the history
feat: add an "ipfs diag profile" command
  • Loading branch information
Stebalien committed Jul 22, 2021
2 parents 748062a + 9c1bb99 commit 5bf5a58
Show file tree
Hide file tree
Showing 8 changed files with 355 additions and 35 deletions.
1 change: 1 addition & 0 deletions core/commands/commands_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -117,6 +117,7 @@ func TestCommands(t *testing.T) {
"/diag/cmds",
"/diag/cmds/clear",
"/diag/cmds/set-time",
"/diag/profile",
"/diag/sys",
"/dns",
"/file",
Expand Down
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,
},
}
237 changes: 237 additions & 0 deletions core/commands/profile.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,237 @@
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/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{
Helptext: cmds.HelpText{
Tagline: "Collect a performance profile for debugging.",
ShortDescription: `
Collects cpu, heap, and goroutine profiles from a running go-ipfs daemon
into a single zip file. To aid in debugging, this command also attempts to
include a copy of the running go-ipfs binary.
`,
LongDescription: `
Collects cpu, heap, and goroutine profiles from a running go-ipfs daemon
into a single zipfile. To aid in debugging, this command also attempts to
include a copy of the running go-ipfs binary.
Profile's can be examined using 'go tool pprof', some tips can be found at
https://github.com/ipfs/go-ipfs/blob/master/docs/debug-guide.md.
Privacy Notice:
The output file includes:
- A list of running goroutines.
- A CPU profile.
- A heap profile.
- Your copy of go-ipfs.
- The output of 'ipfs version --all'.
It does not include:
- Any of your IPFS data or metadata.
- Your config or private key.
- Your IP address.
- The contents of your computer's memory, filesystem, etc.
However, it could reveal:
- Your build path, if you built go-ipfs yourself.
- If and how a command/feature is being used (inferred from running functions).
- Memory offsets of various data structures.
- Any modifications you've made to go-ipfs.
`,
},
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)
}

r, w := io.Pipe()
go func() {
_ = w.CloseWithError(writeProfiles(req.Context, 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, 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 version info
// I'd use diag sysinfo, but that includes some more sensitive information
// (GOPATH, etc.).
{
out, err := archive.Create("version.json")
if err != nil {
return err
}

err = json.NewEncoder(out).Encode(getVersionInfo())
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
18 changes: 11 additions & 7 deletions core/commands/version.go
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,16 @@ const (
versionAllOptionName = "all"
)

func getVersionInfo() *VersionOutput {
return &VersionOutput{
Version: version.CurrentVersionNumber,
Commit: version.CurrentCommit,
Repo: fmt.Sprint(fsrepo.RepoVersion),
System: runtime.GOARCH + "/" + runtime.GOOS, //TODO: Precise version here
Golang: runtime.Version(),
}
}

var VersionCmd = &cmds.Command{
Helptext: cmds.HelpText{
Tagline: "Show IPFS version information.",
Expand All @@ -46,13 +56,7 @@ var VersionCmd = &cmds.Command{
// must be permitted to run before init
Extra: CreateCmdExtras(SetDoesNotUseRepo(true), SetDoesNotUseConfigAsInput(true)),
Run: func(req *cmds.Request, res cmds.ResponseEmitter, env cmds.Environment) error {
return cmds.EmitOnce(res, &VersionOutput{
Version: version.CurrentVersionNumber,
Commit: version.CurrentCommit,
Repo: fmt.Sprint(fsrepo.RepoVersion),
System: runtime.GOARCH + "/" + runtime.GOOS, //TODO: Precise version here
Golang: runtime.Version(),
})
return cmds.EmitOnce(res, getVersionInfo())
},
Encoders: cmds.EncoderMap{
cmds.Text: cmds.MakeTypedEncoder(func(req *cmds.Request, w io.Writer, version *VersionOutput) error {
Expand Down
8 changes: 5 additions & 3 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 Expand Up @@ -79,6 +79,9 @@ that goroutine in the middle of a short wait for something. If the wait time is
over a few minutes, that either means that goroutine doesn't do much, or
something is pretty wrong.

If you're seeing a lot of goroutines, consider using
[stackparse](https://github.com/whyrusleeping/stackparse) to filter, sort, and summarize them.

### Analyzing the CPU Profile

The go team wrote an [excellent article on profiling go
Expand All @@ -97,4 +100,3 @@ The output is JSON formatted and includes badger store statistics, the command l
If you have any questions, or want us to analyze some weird go-ipfs behaviour,
just let us know, and be sure to include all the profiling information
mentioned at the top.

Loading

0 comments on commit 5bf5a58

Please sign in to comment.