From 282eb13a6f1e7db18a3654056d59511f1d433765 Mon Sep 17 00:00:00 2001 From: Guillermo Paoletti Date: Tue, 20 Jul 2021 14:50:17 +0200 Subject: [PATCH] rpc: implement internal `debug_` API namespace functions (#313) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * API Hello World * Added all the debug functions + more data to try implementing the GC functions * Getting transactions information * Added cpu profile first approach functions * new struct for cpuprofile and read filename from params * cpuprofile, gcstats and memstats * added comment * All endpoints returns error instead of string * Code cleanup * Changed errors messages to match go-eth returns * Removed activated flag and just using the file to check if it's running * Added new endpoints to the json_rpc.md file * GoTrace debug endpoints added * Block profile endpoint added * missing goeth calls * added debug logs * divide debug and internal api * Using ExpandHome on server configuration * Added rpc changes to changelog * Logging go trace status * Removed logger functions and moved logger errors to debug * Added more logs to go trace * Added more datailed changelog * Removed trace debug api interface * added comments * cleanup * Updated changelog * disable lint on cpuprofile rename Co-authored-by: Federico Kunze Küllmer <31522760+fedekunze@users.noreply.github.com> * return error in StopCpuProfile Co-authored-by: Federico Kunze Küllmer <31522760+fedekunze@users.noreply.github.com> * return error in StopGoTrace Co-authored-by: Federico Kunze Küllmer <31522760+fedekunze@users.noreply.github.com> * implement suggested changes Co-authored-by: ramacarlucho Co-authored-by: Federico Kunze Küllmer <31522760+fedekunze@users.noreply.github.com> --- CHANGELOG.md | 1 + docs/basics/json_rpc.md | 31 +-- ethereum/rpc/apis.go | 8 + ethereum/rpc/namespaces/debug/internal.go | 216 ++++++++++++++++++ ethereum/rpc/namespaces/debug/trace.go | 69 ++++++ .../rpc/namespaces/debug/trace_fallback.go | 35 +++ ethereum/rpc/namespaces/debug/utils.go | 53 +++++ server/start.go | 5 +- 8 files changed, 403 insertions(+), 15 deletions(-) create mode 100644 ethereum/rpc/namespaces/debug/internal.go create mode 100644 ethereum/rpc/namespaces/debug/trace.go create mode 100644 ethereum/rpc/namespaces/debug/trace_fallback.go create mode 100644 ethereum/rpc/namespaces/debug/utils.go diff --git a/CHANGELOG.md b/CHANGELOG.md index 358f493f..35646bf8 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -69,6 +69,7 @@ Ref: https://keepachangelog.com/en/1.0.0/ * (rpc) [tharsis#112](https://github.com/tharsis/ethermint/pull/153) Fix `eth_coinbase` to return the ethereum address of the validator * (rpc) [tharsis#176](https://github.com/tharsis/ethermint/issues/176) Support fetching pending nonce * (rpc) [tharsis#272](https://github.com/tharsis/ethermint/pull/272) do binary search to estimate gas accurately +* (rpc) [#313](https://github.com/tharsis/ethermint/pull/313) Implement internal debug namespace (Not including logger functions nor traces). ### Bug Fixes diff --git a/docs/basics/json_rpc.md b/docs/basics/json_rpc.md index f39d32b8..8ccca9f7 100644 --- a/docs/basics/json_rpc.md +++ b/docs/basics/json_rpc.md @@ -103,21 +103,25 @@ Check the JSON-RPC methods and namespaces supported on Ethermint. {synopsis} | `clique_discard` | Clique | | | | `clique_status` | Clique | | | | `debug_backtraceAt` | Debug | | | -| `debug_blockProfile` | Debug | | | -| `debug_cpuProfile` | Debug | | | +| `debug_blockProfile` | Debug | ✔ | | +| `debug_cpuProfile` | Debug | ✔ | | | `debug_dumpBlock` | Debug | | | -| `debug_gcStats` | Debug | | | +| `debug_gcStats` | Debug | ✔ | | | `debug_getBlockRlp` | Debug | | | -| `debug_goTrace` | Debug | | | -| `debug_memStats` | Debug | | | +| `debug_goTrace` | Debug | ✔ | | +| `debug_freeOSMemory` | Debug | ✔ | | +| `debug_memStats` | Debug | ✔ | | +| `debug_mutexProfile` | Debug | ✔ | | | `debug_seedHash` | Debug | | | | `debug_setHead` | Debug | | | -| `debug_setBlockProfileRate` | Debug | | | -| `debug_stacks` | Debug | | | -| `debug_startCPUProfile` | Debug | | | -| `debug_startGoTrace` | Debug | | | -| `debug_stopCPUProfile` | Debug | | | -| `debug_stopGoTrace` | Debug | | | +| `debug_setBlockProfileRate` | Debug | ✔ | | +| `debug_setGCPercent` | Debug | ✔ | | +| `debug_setMutexProfileFraction` | Debug | ✔ | | +| `debug_stacks` | Debug | ✔ | | +| `debug_startCPUProfile` | Debug | ✔ | | +| `debug_startGoTrace` | Debug | ✔ | | +| `debug_stopCPUProfile` | Debug | ✔ | | +| `debug_stopGoTrace` | Debug | ✔ | | | `debug_traceBlock` | Debug | | | | `debug_traceBlockByNumber` | Debug | | | | `debug_traceBlockByHash` | Debug | | | @@ -127,8 +131,9 @@ Check the JSON-RPC methods and namespaces supported on Ethermint. {synopsis} | `debug_traceTransaction` | Debug | | | | `debug_verbosity` | Debug | | | | `debug_vmodule` | Debug | | | -| `debug_writeBlockProfile` | Debug | | | -| `debug_writeMemProfile` | Debug | | | +| `debug_writeBlockProfile` | Debug | ✔ | | +| `debug_writeMemProfile` | Debug | ✔ | | +| `debug_writeMutexProfile` | Debug | ✔ | | | `les_serverInfo` | Les | | | | `les_clientInfo` | Les | | | | `les_priorityClientInfo` | Les | | | diff --git a/ethereum/rpc/apis.go b/ethereum/rpc/apis.go index d101f389..898d7a8a 100644 --- a/ethereum/rpc/apis.go +++ b/ethereum/rpc/apis.go @@ -8,6 +8,7 @@ import ( "github.com/ethereum/go-ethereum/rpc" "github.com/tharsis/ethermint/ethereum/rpc/backend" + "github.com/tharsis/ethermint/ethereum/rpc/namespaces/debug" "github.com/tharsis/ethermint/ethereum/rpc/namespaces/eth" "github.com/tharsis/ethermint/ethereum/rpc/namespaces/eth/filters" "github.com/tharsis/ethermint/ethereum/rpc/namespaces/net" @@ -26,6 +27,7 @@ const ( PersonalNamespace = "personal" NetNamespace = "net" TxPoolNamespace = "txpool" + DebugNamespace = "debug" apiVersion = "1.0" ) @@ -73,5 +75,11 @@ func GetRPCAPIs(ctx *server.Context, clientCtx client.Context, tmWSClient *rpccl Service: txpool.NewPublicAPI(ctx.Logger), Public: true, }, + { + Namespace: DebugNamespace, + Version: apiVersion, + Service: debug.NewInternalAPI(ctx), + Public: true, + }, } } diff --git a/ethereum/rpc/namespaces/debug/internal.go b/ethereum/rpc/namespaces/debug/internal.go new file mode 100644 index 00000000..6675af81 --- /dev/null +++ b/ethereum/rpc/namespaces/debug/internal.go @@ -0,0 +1,216 @@ +package debug + +import ( + "bytes" + "errors" + "io" + "os" + "runtime" + "runtime/debug" + "runtime/pprof" + "sync" + "time" + + "github.com/cosmos/cosmos-sdk/server" + "github.com/tendermint/tendermint/libs/log" +) + +// HandlerT keeps track of the cpu profiler and trace execution +type HandlerT struct { + cpuFilename string + cpuFile io.WriteCloser + mu sync.Mutex + traceFilename string + traceFile io.WriteCloser +} + +// InternalAPI is the debug_ prefixed set of APIs in the Debug JSON-RPC spec. +type InternalAPI struct { + ctx *server.Context + logger log.Logger + handler *HandlerT +} + +// NewInternalAPI creates an instance of the Debug API. +func NewInternalAPI( + ctx *server.Context, +) *InternalAPI { + return &InternalAPI{ + ctx: ctx, + logger: ctx.Logger.With("module", "debug"), + handler: new(HandlerT), + } +} + +// BlockProfile turns on goroutine profiling for nsec seconds and writes profile data to +// file. It uses a profile rate of 1 for most accurate information. If a different rate is +// desired, set the rate and write the profile manually. +func (a *InternalAPI) BlockProfile(file string, nsec uint) error { + a.logger.Debug("debug_blockProfile", "file", file, "nsec", nsec) + runtime.SetBlockProfileRate(1) + defer runtime.SetBlockProfileRate(0) + + time.Sleep(time.Duration(nsec) * time.Second) + return writeProfile("block", file, a.logger) +} + +// CpuProfile turns on CPU profiling for nsec seconds and writes +// profile data to file. +func (a *InternalAPI) CpuProfile(file string, nsec uint) error { // nolint: golint + a.logger.Debug("debug_cpuProfile", "file", file, "nsec", nsec) + if err := a.StartCPUProfile(file); err != nil { + return err + } + time.Sleep(time.Duration(nsec) * time.Second) + return a.StopCPUProfile() +} + +// GcStats returns GC statistics. +func (a *InternalAPI) GcStats() *debug.GCStats { + a.logger.Debug("debug_gcStats") + s := new(debug.GCStats) + debug.ReadGCStats(s) + return s +} + +// GoTrace turns on tracing for nsec seconds and writes +// trace data to file. +func (a *InternalAPI) GoTrace(file string, nsec uint) error { + a.logger.Debug("debug_goTrace", "file", file, "nsec", nsec) + if err := a.StartGoTrace(file); err != nil { + return err + } + time.Sleep(time.Duration(nsec) * time.Second) + return a.StopGoTrace() +} + +// MemStats returns detailed runtime memory statistics. +func (a *InternalAPI) MemStats() *runtime.MemStats { + a.logger.Debug("debug_memStats") + s := new(runtime.MemStats) + runtime.ReadMemStats(s) + return s +} + +// SetBlockProfileRate sets the rate of goroutine block profile data collection. +// rate 0 disables block profiling. +func (a *InternalAPI) SetBlockProfileRate(rate int) { + a.logger.Debug("debug_setBlockProfileRate", "rate", rate) + runtime.SetBlockProfileRate(rate) +} + +// Stacks returns a printed representation of the stacks of all goroutines. +func (a *InternalAPI) Stacks() string { + a.logger.Debug("debug_stacks") + buf := new(bytes.Buffer) + err := pprof.Lookup("goroutine").WriteTo(buf, 2) + if err != nil { + a.logger.Error("Failed to create stacks", "error", err.Error()) + } + return buf.String() +} + +// StartCPUProfile turns on CPU profiling, writing to the given file. +func (a *InternalAPI) StartCPUProfile(file string) error { + a.logger.Debug("debug_startCPUProfile", "file", file) + a.handler.mu.Lock() + defer a.handler.mu.Unlock() + + switch { + case isCPUProfileConfigurationActivated(a.ctx): + a.logger.Debug("CPU profiling already in progress using the configuration file") + return errors.New("CPU profiling already in progress using the configuration file") + case a.handler.cpuFile != nil: + a.logger.Debug("CPU profiling already in progress") + return errors.New("CPU profiling already in progress") + default: + f, err := os.Create(ExpandHome(file)) + if err != nil { + a.logger.Debug("failed to create CPU profile file", "error", err.Error()) + return err + } + if err := pprof.StartCPUProfile(f); err != nil { + a.logger.Debug("cpu profiling already in use", "error", err.Error()) + f.Close() + return err + } + + a.logger.Info("CPU profiling started", "profile", file) + a.handler.cpuFile = f + a.handler.cpuFilename = file + return nil + } +} + +// StopCPUProfile stops an ongoing CPU profile. +func (a *InternalAPI) StopCPUProfile() error { + a.logger.Debug("debug_stopCPUProfile") + a.handler.mu.Lock() + defer a.handler.mu.Unlock() + + switch { + case isCPUProfileConfigurationActivated(a.ctx): + a.logger.Debug("CPU profiling already in progress using the configuration file") + return errors.New("CPU profiling already in progress using the configuration file") + case a.handler.cpuFile != nil: + a.logger.Info("Done writing CPU profile", "profile", a.handler.cpuFilename) + pprof.StopCPUProfile() + a.handler.cpuFile.Close() + a.handler.cpuFile = nil + a.handler.cpuFilename = "" + return nil + default: + a.logger.Debug("CPU profiling not in progress") + return errors.New("CPU profiling not in progress") + } +} + +// WriteBlockProfile writes a goroutine blocking profile to the given file. +func (a *InternalAPI) WriteBlockProfile(file string) error { + a.logger.Debug("debug_writeBlockProfile", "file", file) + return writeProfile("block", file, a.logger) +} + +// WriteMemProfile writes an allocation profile to the given file. +// Note that the profiling rate cannot be set through the API, +// it must be set on the command line. +func (a *InternalAPI) WriteMemProfile(file string) error { + a.logger.Debug("debug_writeMemProfile", "file", file) + return writeProfile("heap", file, a.logger) +} + +// MutexProfile turns on mutex profiling for nsec seconds and writes profile data to file. +// It uses a profile rate of 1 for most accurate information. If a different rate is +// desired, set the rate and write the profile manually. +func (a *InternalAPI) MutexProfile(file string, nsec uint) error { + a.logger.Debug("debug_mutexProfile", "file", file, "nsec", nsec) + runtime.SetMutexProfileFraction(1) + time.Sleep(time.Duration(nsec) * time.Second) + defer runtime.SetMutexProfileFraction(0) + return writeProfile("mutex", file, a.logger) +} + +// SetMutexProfileFraction sets the rate of mutex profiling. +func (a *InternalAPI) SetMutexProfileFraction(rate int) { + a.logger.Debug("debug_setMutexProfileFraction", "rate", rate) + runtime.SetMutexProfileFraction(rate) +} + +// WriteMutexProfile writes a goroutine blocking profile to the given file. +func (a *InternalAPI) WriteMutexProfile(file string) error { + a.logger.Debug("debug_writeMutexProfile", "file", file) + return writeProfile("mutex", file, a.logger) +} + +// FreeOSMemory forces a garbage collection. +func (a *InternalAPI) FreeOSMemory() { + a.logger.Debug("debug_freeOSMemory") + debug.FreeOSMemory() +} + +// SetGCPercent sets the garbage collection target percentage. It returns the previous +// setting. A negative value disables GC. +func (a *InternalAPI) SetGCPercent(v int) int { + a.logger.Debug("debug_setGCPercent", "percent", v) + return debug.SetGCPercent(v) +} diff --git a/ethereum/rpc/namespaces/debug/trace.go b/ethereum/rpc/namespaces/debug/trace.go new file mode 100644 index 00000000..501abb8c --- /dev/null +++ b/ethereum/rpc/namespaces/debug/trace.go @@ -0,0 +1,69 @@ +// Copyright 2016 The go-ethereum Authors +// This file is part of the go-ethereum library. +// +// The go-ethereum library is free software: you can redistribute it and/or modify +// it under the terms of the GNU Lesser General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// The go-ethereum library is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU Lesser General Public License for more details. +// +// You should have received a copy of the GNU Lesser General Public License +// along with the go-ethereum library. If not, see . + +//+build go1.5 + +package debug + +import ( + "errors" + "os" + "runtime/trace" +) + +// StartGoTrace turns on tracing, writing to the given file. +func (a *InternalAPI) StartGoTrace(file string) error { + a.logger.Debug("debug_stopGoTrace", "file", file) + a.handler.mu.Lock() + defer a.handler.mu.Unlock() + + if a.handler.traceFile != nil { + a.logger.Debug("trace already in progress") + return errors.New("trace already in progress") + } + f, err := os.Create(ExpandHome(file)) + if err != nil { + a.logger.Debug("failed to create go trace file", "error", err.Error()) + return err + } + if err := trace.Start(f); err != nil { + a.logger.Debug("Go tracing already started", "error", err.Error()) + f.Close() + return err + } + a.handler.traceFile = f + a.handler.traceFilename = file + a.logger.Info("Go tracing started", "dump", a.handler.traceFilename) + return nil +} + +// StopGoTrace stops an ongoing trace. +func (a *InternalAPI) StopGoTrace() error { + a.logger.Debug("debug_stopGoTrace") + a.handler.mu.Lock() + defer a.handler.mu.Unlock() + + trace.Stop() + if a.handler.traceFile == nil { + a.logger.Debug("trace not in progress") + return errors.New("trace not in progress") + } + a.logger.Info("Done writing Go trace", "dump", a.handler.traceFilename) + a.handler.traceFile.Close() + a.handler.traceFile = nil + a.handler.traceFilename = "" + return nil +} diff --git a/ethereum/rpc/namespaces/debug/trace_fallback.go b/ethereum/rpc/namespaces/debug/trace_fallback.go new file mode 100644 index 00000000..67fdee39 --- /dev/null +++ b/ethereum/rpc/namespaces/debug/trace_fallback.go @@ -0,0 +1,35 @@ +// Copyright 2016 The go-ethereum Authors +// This file is part of the go-ethereum library. +// +// The go-ethereum library is free software: you can redistribute it and/or modify +// it under the terms of the GNU Lesser General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// The go-ethereum library is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU Lesser General Public License for more details. +// +// You should have received a copy of the GNU Lesser General Public License +// along with the go-ethereum library. If not, see . + +//+build !go1.5 + +// no-op implementation of tracing methods for Go < 1.5. + +package debug + +import ( + "errors" +) + +func (*InternalAPI) StartGoTrace(string file) error { + a.logger.Debug("debug_stopGoTrace", "file", file) + return errors.New("tracing is not supported on Go < 1.5") +} + +func (*InternalAPI) StopGoTrace() error { + a.logger.Debug("debug_stopGoTrace") + return errors.New("tracing is not supported on Go < 1.5") +} diff --git a/ethereum/rpc/namespaces/debug/utils.go b/ethereum/rpc/namespaces/debug/utils.go new file mode 100644 index 00000000..ebc53df7 --- /dev/null +++ b/ethereum/rpc/namespaces/debug/utils.go @@ -0,0 +1,53 @@ +package debug + +import ( + "os" + "os/user" + "path/filepath" + "runtime/pprof" + "strings" + + "github.com/cosmos/cosmos-sdk/server" + "github.com/tendermint/tendermint/libs/log" +) + +// isCPUProfileConfigurationActivated checks if cpuprofile was configured via flag +func isCPUProfileConfigurationActivated(ctx *server.Context) bool { + // TODO: use same constants as server/start.go + // constant declared in start.go cannot be imported (cyclical dependency) + const flagCPUProfile = "cpu-profile" + if cpuProfile := ctx.Viper.GetString(flagCPUProfile); cpuProfile != "" { + return true + } + return false +} + +// ExpandHome expands home directory in file paths. +// ~someuser/tmp will not be expanded. +func ExpandHome(p string) string { + if strings.HasPrefix(p, "~/") || strings.HasPrefix(p, "~\\") { + home := os.Getenv("HOME") + if home == "" { + if usr, err := user.Current(); err == nil { + home = usr.HomeDir + } + } + if home != "" { + p = home + p[1:] + } + } + return filepath.Clean(p) +} + +// writeProfile writes the data to a file +func writeProfile(name, file string, log log.Logger) error { + p := pprof.Lookup(name) + log.Info("Writing profile records", "count", p.Count(), "type", name, "dump", file) + f, err := os.Create(ExpandHome(file)) + if err != nil { + return err + } + defer f.Close() + + return p.WriteTo(f, 0) +} diff --git a/server/start.go b/server/start.go index 6bc635e2..4c6c6afa 100644 --- a/server/start.go +++ b/server/start.go @@ -40,6 +40,7 @@ import ( "github.com/tharsis/ethermint/cmd/ethermintd/config" "github.com/tharsis/ethermint/ethereum/rpc" + ethdebug "github.com/tharsis/ethermint/ethereum/rpc/namespaces/debug" ) // Tendermint full-node start flags @@ -339,9 +340,9 @@ func startInProcess(ctx *server.Context, clientCtx client.Context, appCreator ty var cpuProfileCleanup func() if cpuProfile := ctx.Viper.GetString(flagCPUProfile); cpuProfile != "" { - f, err := os.Create(cpuProfile) + f, err := os.Create(ethdebug.ExpandHome(cpuProfile)) if err != nil { - logger.Error("failed to create CP profile", "error", err.Error()) + logger.Error("failed to create CPU profile", "error", err.Error()) return err }