From ef140c0b937501bc19ed24c3c5d61854e334512b Mon Sep 17 00:00:00 2001 From: niklr Date: Tue, 15 Jun 2021 00:30:03 +0200 Subject: [PATCH] Implement pprof module extension --- .gitignore | 3 + api/service/manager.go | 3 + api/service/pprof/service.go | 225 ++++++++++++++++++++++++++++ api/service/pprof/service_test.go | 80 ++++++++++ cmd/harmony/config_migrations.go | 22 +++ cmd/harmony/default.go | 6 +- cmd/harmony/flags.go | 43 ++++++ cmd/harmony/flags_test.go | 63 +++++++- cmd/harmony/main.go | 30 ++-- internal/cli/flag.go | 19 +++ internal/cli/parse.go | 21 +++ internal/configs/harmony/harmony.go | 8 +- 12 files changed, 498 insertions(+), 25 deletions(-) create mode 100644 api/service/pprof/service.go create mode 100644 api/service/pprof/service_test.go diff --git a/.gitignore b/.gitignore index a686e5da9..2932860c9 100644 --- a/.gitignore +++ b/.gitignore @@ -91,3 +91,6 @@ explorer_storage_* # local blskeys for testing .hmy/blskeys + +# pprof profiles +profiles/*.pb.gz \ No newline at end of file diff --git a/api/service/manager.go b/api/service/manager.go index 1bb53137b..3e286fe1b 100644 --- a/api/service/manager.go +++ b/api/service/manager.go @@ -20,6 +20,7 @@ const ( Consensus BlockProposal NetworkInfo + Pprof Prometheus Synchronize ) @@ -36,6 +37,8 @@ func (t Type) String() string { return "BlockProposal" case NetworkInfo: return "NetworkInfo" + case Pprof: + return "Pprof" case Prometheus: return "Prometheus" case Synchronize: diff --git a/api/service/pprof/service.go b/api/service/pprof/service.go new file mode 100644 index 000000000..ebde4c208 --- /dev/null +++ b/api/service/pprof/service.go @@ -0,0 +1,225 @@ +package pprof + +import ( + "fmt" + "log" + "net/http" + "os" + "path/filepath" + "runtime/pprof" + "sync" + "time" + + "github.com/ethereum/go-ethereum/rpc" + "github.com/harmony-one/harmony/internal/utils" +) + +// Config is the config for the pprof service +type Config struct { + Enabled bool + ListenAddr string + Folder string + ProfileNames []string + ProfileIntervals []int + ProfileDebugValues []int +} + +type Profile struct { + Name string + Interval int + Debug int + ProfileRef *pprof.Profile +} + +func (p Config) String() string { + return fmt.Sprintf("%v, %v, %v, %v/%v/%v", p.Enabled, p.ListenAddr, p.Folder, p.ProfileNames, p.ProfileIntervals, p.ProfileDebugValues) +} + +// Constants for profile names +const ( + CPU = "cpu" +) + +// Service provides access to pprof profiles via HTTP and can save them to local disk periodically as user settings. +type Service struct { + config Config + profiles map[string]Profile +} + +var ( + initOnce sync.Once + svc = &Service{} +) + +// NewService creates the new pprof service +func NewService(cfg Config) *Service { + initOnce.Do(func() { + svc = newService(cfg) + }) + return svc +} + +func newService(cfg Config) *Service { + if !cfg.Enabled { + utils.Logger().Info().Msg("Pprof service disabled...") + return nil + } + + utils.Logger().Debug().Str("cfg", cfg.String()).Msg("Pprof") + svc.config = cfg + + if profiles, err := cfg.unpackProfilesIntoMap(); err != nil { + log.Fatal("Could not unpack pprof profiles into map") + } else { + svc.profiles = profiles + } + + go func() { + utils.Logger().Info().Str("address", cfg.ListenAddr).Msg("Starting pprof HTTP service") + http.ListenAndServe(cfg.ListenAddr, nil) + }() + + return svc +} + +// Start start the service +func (s *Service) Start() error { + dir, err := filepath.Abs(s.config.Folder) + if err != nil { + return err + } + err = os.MkdirAll(dir, os.FileMode(0755)) + if err != nil { + return err + } + + if cpuProfile, ok := s.profiles[CPU]; ok { + go handleCpuProfile(cpuProfile, dir) + } + + for _, profile := range s.profiles { + scheduleProfile(profile, dir) + } + + return nil +} + +// Stop stop the service +func (s *Service) Stop() error { + dir, err := filepath.Abs(s.config.Folder) + if err != nil { + return err + } + for _, profile := range s.profiles { + if profile.Name == CPU { + pprof.StopCPUProfile() + } else { + saveProfile(profile, dir) + } + } + return nil +} + +// APIs return all APIs of the service +func (s *Service) APIs() []rpc.API { + return nil +} + +// scheduleProfile schedules the provided profile based on the specified interval (e.g. saves the profile every x seconds) +func scheduleProfile(profile Profile, dir string) { + go func() { + if profile.Interval > 0 { + ticker := time.NewTicker(time.Second * time.Duration(profile.Interval)) + defer ticker.Stop() + for { + select { + case <-ticker.C: + if profile.Name == CPU { + handleCpuProfile(profile, dir) + } else { + saveProfile(profile, dir) + } + } + } + } + }() +} + +// saveProfile saves the provided profile in the specified directory +func saveProfile(profile Profile, dir string) error { + f, err := newTempFile(dir, profile.Name, ".pb.gz") + if err != nil { + utils.Logger().Error().Err(err).Msg(fmt.Sprintf("Could not save profile: %s", profile.Name)) + return err + } + defer f.Close() + if profile.ProfileRef != nil { + err = profile.ProfileRef.WriteTo(f, profile.Debug) + if err != nil { + utils.Logger().Error().Err(err).Msg(fmt.Sprintf("Could not write profile: %s", profile.Name)) + return err + } + utils.Logger().Info().Msg(fmt.Sprintf("Saved profile in: %s", f.Name())) + } + return nil +} + +// handleCpuProfile handles the provided CPU profile +func handleCpuProfile(profile Profile, dir string) { + pprof.StopCPUProfile() + f, err := newTempFile(dir, profile.Name, ".pb.gz") + if err == nil { + pprof.StartCPUProfile(f) + utils.Logger().Info().Msg(fmt.Sprintf("Saved CPU profile in: %s", f.Name())) + } else { + utils.Logger().Error().Err(err).Msg("Could not start CPU profile") + } +} + +// unpackProfilesIntoMap unpacks the profiles specified in the configuration into a map +func (config *Config) unpackProfilesIntoMap() (map[string]Profile, error) { + result := make(map[string]Profile, len(config.ProfileNames)) + if len(config.ProfileNames) == 0 { + return nil, nil + } + for index, name := range config.ProfileNames { + profile := Profile{ + Name: name, + Interval: 0, + Debug: 0, + } + // Try set interval value + if len(config.ProfileIntervals) == len(config.ProfileNames) { + profile.Interval = config.ProfileIntervals[index] + } else if len(config.ProfileIntervals) > 0 { + profile.Interval = config.ProfileIntervals[0] + } + // Try set debug value + if len(config.ProfileDebugValues) == len(config.ProfileNames) { + profile.Debug = config.ProfileDebugValues[index] + } else if len(config.ProfileDebugValues) > 0 { + profile.Debug = config.ProfileDebugValues[0] + } + // Try set the profile reference + if profile.Name != CPU { + if p := pprof.Lookup(profile.Name); p == nil { + return nil, fmt.Errorf("Profile does not exist: %s", profile.Name) + } else { + profile.ProfileRef = p + } + } + result[name] = profile + } + return result, nil +} + +// newTempFile returns a new output file in dir with the provided prefix and suffix. +func newTempFile(dir, name, suffix string) (*os.File, error) { + prefix := name + "." + currentTime := time.Now().Unix() + f, err := os.OpenFile(filepath.Join(dir, fmt.Sprintf("%s%d%s", prefix, currentTime, suffix)), os.O_RDWR|os.O_CREATE|os.O_EXCL, 0666) + if err != nil { + return nil, fmt.Errorf("could not create file of the form %s%d%s", prefix, currentTime, suffix) + } + return f, nil +} diff --git a/api/service/pprof/service_test.go b/api/service/pprof/service_test.go new file mode 100644 index 000000000..5544017ba --- /dev/null +++ b/api/service/pprof/service_test.go @@ -0,0 +1,80 @@ +package pprof + +import ( + "errors" + "fmt" + "reflect" + "strings" + "testing" +) + +func TestUnpackProfilesIntoMap(t *testing.T) { + tests := []struct { + input *Config + expMap map[string]Profile + expErr error + }{ + { + input: &Config{}, + expMap: make(map[string]Profile), + }, + { + input: &Config{ + ProfileNames: []string{"test", "test"}, + }, + expMap: nil, + expErr: errors.New("Pprof profile names contains duplicate: test"), + }, + { + input: &Config{ + ProfileNames: []string{"test"}, + }, + expMap: map[string]Profile{ + "test": { + Name: "test", + }, + }, + }, + { + input: &Config{ + ProfileNames: []string{"test1", "test2"}, + ProfileIntervals: []int{0, 60}, + ProfileDebugValues: []int{1}, + }, + expMap: map[string]Profile{ + "test1": { + Name: "test1", + Interval: 0, + Debug: 1, + }, + "test2": { + Name: "test2", + Interval: 60, + Debug: 1, + }, + }, + }, + } + for i, test := range tests { + actual, err := test.input.unpackProfilesIntoMap() + if assErr := assertError(err, test.expErr); assErr != nil { + t.Fatalf("Test %v: %v", i, assErr) + } + if !reflect.DeepEqual(actual, test.expMap) { + t.Errorf("Test %v: unexpected map\n\t%+v\n\t%+v", i, actual, test.expMap) + } + } +} + +func assertError(gotErr, expErr error) error { + if (gotErr == nil) != (expErr == nil) { + return fmt.Errorf("error unexpected [%v] / [%v]", gotErr, expErr) + } + if gotErr == nil { + return nil + } + if !strings.Contains(gotErr.Error(), expErr.Error()) { + return fmt.Errorf("error unexpected [%v] / [%v]", gotErr, expErr) + } + return nil +} diff --git a/cmd/harmony/config_migrations.go b/cmd/harmony/config_migrations.go index 9e986fa03..4fb31c0d4 100644 --- a/cmd/harmony/config_migrations.go +++ b/cmd/harmony/config_migrations.go @@ -167,4 +167,26 @@ func init() { confTree.Set("Version", "2.1.0") return confTree } + + migrations["2.1.0"] = func(confTree *toml.Tree) *toml.Tree { + // Legacy conf missing fields + if confTree.Get("Pprof.Enabled") == nil { + confTree.Set("Pprof.Enabled", true) + } + if confTree.Get("Pprof.Folder") == nil { + confTree.Set("Pprof.Folder", defaultConfig.Pprof.Folder) + } + if confTree.Get("Pprof.ProfileNames") == nil { + confTree.Set("Pprof.ProfileNames", "") + } + if confTree.Get("Pprof.ProfileIntervals") == nil { + confTree.Set("Pprof.ProfileIntervals", "") + } + if confTree.Get("Pprof.ProfileDebugValues") == nil { + confTree.Set("Pprof.ProfileDebugValues", "") + } + + confTree.Set("Version", "2.2.0") + return confTree + } } diff --git a/cmd/harmony/default.go b/cmd/harmony/default.go index 4b76c6203..cc6a4e3c6 100644 --- a/cmd/harmony/default.go +++ b/cmd/harmony/default.go @@ -63,8 +63,10 @@ var defaultConfig = harmonyconfig.HarmonyConfig{ }, Sync: getDefaultSyncConfig(defNetworkType), Pprof: harmonyconfig.PprofConfig{ - Enabled: false, - ListenAddr: "127.0.0.1:6060", + Enabled: false, + ListenAddr: "127.0.0.1:6060", + Folder: "./profiles", + ProfileNames: []string{}, }, Log: harmonyconfig.LogConfig{ Folder: "./latest", diff --git a/cmd/harmony/flags.go b/cmd/harmony/flags.go index c34c23b9a..abaf5de49 100644 --- a/cmd/harmony/flags.go +++ b/cmd/harmony/flags.go @@ -126,6 +126,10 @@ var ( pprofFlags = []cli.Flag{ pprofEnabledFlag, pprofListenAddrFlag, + pprofFolderFlag, + pprofProfileNamesFlag, + pprofProfileIntervalFlag, + pprofProfileDebugFlag, } logFlags = []cli.Flag{ @@ -963,6 +967,29 @@ var ( Usage: "listen address for pprof", DefValue: defaultConfig.Pprof.ListenAddr, } + pprofFolderFlag = cli.StringFlag{ + Name: "pprof.folder", + Usage: "folder to put pprof profiles", + DefValue: defaultConfig.Pprof.Folder, + Hidden: true, + } + pprofProfileNamesFlag = cli.StringSliceFlag{ + Name: "pprof.profile.names", + Usage: "a list of pprof profile names (separated by ,) e.g. cpu,heap,goroutine", + DefValue: defaultConfig.Pprof.ProfileNames, + } + pprofProfileIntervalFlag = cli.IntSliceFlag{ + Name: "pprof.profile.intervals", + Usage: "a list of pprof profile interval integer values (separated by ,) e.g. 30 saves all profiles every 30 seconds or 0,10 saves the first profile on shutdown and the second profile every 10 seconds", + DefValue: defaultConfig.Pprof.ProfileIntervals, + Hidden: true, + } + pprofProfileDebugFlag = cli.IntSliceFlag{ + Name: "pprof.profile.debug", + Usage: "a list of pprof profile debug integer values (separated by ,) e.g. 0 writes the gzip-compressed protocol buffer and 1 writes the legacy text format", + DefValue: defaultConfig.Pprof.ProfileDebugValues, + Hidden: true, + } ) func applyPprofFlags(cmd *cobra.Command, config *harmonyconfig.HarmonyConfig) { @@ -971,6 +998,22 @@ func applyPprofFlags(cmd *cobra.Command, config *harmonyconfig.HarmonyConfig) { config.Pprof.ListenAddr = cli.GetStringFlagValue(cmd, pprofListenAddrFlag) pprofSet = true } + if cli.IsFlagChanged(cmd, pprofFolderFlag) { + config.Pprof.Folder = cli.GetStringFlagValue(cmd, pprofFolderFlag) + pprofSet = true + } + if cli.IsFlagChanged(cmd, pprofProfileNamesFlag) { + config.Pprof.ProfileNames = cli.GetStringSliceFlagValue(cmd, pprofProfileNamesFlag) + pprofSet = true + } + if cli.IsFlagChanged(cmd, pprofProfileIntervalFlag) { + config.Pprof.ProfileIntervals = cli.GetIntSliceFlagValue(cmd, pprofProfileIntervalFlag) + pprofSet = true + } + if cli.IsFlagChanged(cmd, pprofProfileDebugFlag) { + config.Pprof.ProfileDebugValues = cli.GetIntSliceFlagValue(cmd, pprofProfileDebugFlag) + pprofSet = true + } if cli.IsFlagChanged(cmd, pprofEnabledFlag) { config.Pprof.Enabled = cli.GetBoolFlagValue(cmd, pprofEnabledFlag) } else if pprofSet { diff --git a/cmd/harmony/flags_test.go b/cmd/harmony/flags_test.go index bd72fc709..18d03004f 100644 --- a/cmd/harmony/flags_test.go +++ b/cmd/harmony/flags_test.go @@ -98,8 +98,10 @@ func TestHarmonyFlags(t *testing.T) { BlacklistFile: "./.hmy/blacklist.txt", }, Pprof: harmonyconfig.PprofConfig{ - Enabled: false, - ListenAddr: "127.0.0.1:6060", + Enabled: false, + ListenAddr: "127.0.0.1:6060", + Folder: "./profiles", + ProfileNames: []string{}, }, Log: harmonyconfig.LogConfig{ Folder: "./latest", @@ -773,22 +775,67 @@ func TestPprofFlags(t *testing.T) { { args: []string{"--pprof"}, expConfig: harmonyconfig.PprofConfig{ - Enabled: true, - ListenAddr: defaultConfig.Pprof.ListenAddr, + Enabled: true, + ListenAddr: defaultConfig.Pprof.ListenAddr, + Folder: defaultConfig.Pprof.Folder, + ProfileNames: defaultConfig.Pprof.ProfileNames, + ProfileIntervals: defaultConfig.Pprof.ProfileIntervals, + ProfileDebugValues: defaultConfig.Pprof.ProfileDebugValues, }, }, { args: []string{"--pprof.addr", "8.8.8.8:9001"}, expConfig: harmonyconfig.PprofConfig{ - Enabled: true, - ListenAddr: "8.8.8.8:9001", + Enabled: true, + ListenAddr: "8.8.8.8:9001", + Folder: defaultConfig.Pprof.Folder, + ProfileNames: defaultConfig.Pprof.ProfileNames, + ProfileIntervals: defaultConfig.Pprof.ProfileIntervals, + ProfileDebugValues: defaultConfig.Pprof.ProfileDebugValues, }, }, { args: []string{"--pprof=false", "--pprof.addr", "8.8.8.8:9001"}, expConfig: harmonyconfig.PprofConfig{ - Enabled: false, - ListenAddr: "8.8.8.8:9001", + Enabled: false, + ListenAddr: "8.8.8.8:9001", + Folder: defaultConfig.Pprof.Folder, + ProfileNames: defaultConfig.Pprof.ProfileNames, + ProfileIntervals: defaultConfig.Pprof.ProfileIntervals, + ProfileDebugValues: defaultConfig.Pprof.ProfileDebugValues, + }, + }, + { + args: []string{"--pprof.profile.names", "cpu,heap,mutex"}, + expConfig: harmonyconfig.PprofConfig{ + Enabled: true, + ListenAddr: defaultConfig.Pprof.ListenAddr, + Folder: defaultConfig.Pprof.Folder, + ProfileNames: []string{"cpu", "heap", "mutex"}, + ProfileIntervals: defaultConfig.Pprof.ProfileIntervals, + ProfileDebugValues: defaultConfig.Pprof.ProfileDebugValues, + }, + }, + { + args: []string{"--pprof.profile.intervals", "0,1"}, + expConfig: harmonyconfig.PprofConfig{ + Enabled: true, + ListenAddr: defaultConfig.Pprof.ListenAddr, + Folder: defaultConfig.Pprof.Folder, + ProfileNames: defaultConfig.Pprof.ProfileNames, + ProfileIntervals: []int{0, 1}, + ProfileDebugValues: defaultConfig.Pprof.ProfileDebugValues, + }, + }, + { + args: []string{"--pprof.profile.debug", "0,1,0"}, + expConfig: harmonyconfig.PprofConfig{ + Enabled: true, + ListenAddr: defaultConfig.Pprof.ListenAddr, + Folder: defaultConfig.Pprof.Folder, + ProfileNames: defaultConfig.Pprof.ProfileNames, + ProfileIntervals: defaultConfig.Pprof.ProfileIntervals, + ProfileDebugValues: []int{0, 1, 0}, }, }, } diff --git a/cmd/harmony/main.go b/cmd/harmony/main.go index 1e9b32b5c..857dd7447 100644 --- a/cmd/harmony/main.go +++ b/cmd/harmony/main.go @@ -5,7 +5,6 @@ import ( "io/ioutil" "math/big" "math/rand" - "net/http" _ "net/http/pprof" "os" "os/signal" @@ -26,6 +25,7 @@ import ( "github.com/spf13/cobra" "github.com/harmony-one/harmony/api/service" + "github.com/harmony-one/harmony/api/service/pprof" "github.com/harmony-one/harmony/api/service/prometheus" "github.com/harmony-one/harmony/api/service/synchronize" "github.com/harmony-one/harmony/common/fdlimit" @@ -134,7 +134,6 @@ func runHarmonyNode(cmd *cobra.Command, args []string) { } setupNodeLog(cfg) - setupPprof(cfg) setupNodeAndRun(cfg) } @@ -245,17 +244,6 @@ func setupNodeLog(config harmonyconfig.HarmonyConfig) { } } -func setupPprof(config harmonyconfig.HarmonyConfig) { - enabled := config.Pprof.Enabled - addr := config.Pprof.ListenAddr - - if enabled { - go func() { - http.ListenAndServe(addr, nil) - }() - } -} - func setupNodeAndRun(hc harmonyconfig.HarmonyConfig) { var err error @@ -399,6 +387,9 @@ func setupNodeAndRun(hc harmonyconfig.HarmonyConfig) { } else if currentNode.NodeConfig.Role() == nodeconfig.ExplorerNode { currentNode.RegisterExplorerServices() } + if hc.Pprof.Enabled { + setupPprofService(currentNode, hc) + } if hc.Prometheus.Enabled { setupPrometheusService(currentNode, hc, nodeConfig.ShardID) } @@ -731,6 +722,19 @@ func processNodeType(hc harmonyconfig.HarmonyConfig, currentNode *node.Node, cur } } +func setupPprofService(node *node.Node, hc harmonyconfig.HarmonyConfig) { + pprofConfig := pprof.Config{ + Enabled: hc.Pprof.Enabled, + ListenAddr: hc.Pprof.ListenAddr, + Folder: hc.Pprof.Folder, + ProfileNames: hc.Pprof.ProfileNames, + ProfileIntervals: hc.Pprof.ProfileIntervals, + ProfileDebugValues: hc.Pprof.ProfileDebugValues, + } + s := pprof.NewService(pprofConfig) + node.RegisterService(service.Pprof, s) +} + func setupPrometheusService(node *node.Node, hc harmonyconfig.HarmonyConfig, sid uint32) { prometheusConfig := prometheus.Config{ Enabled: hc.Prometheus.Enabled, diff --git a/internal/cli/flag.go b/internal/cli/flag.go index ef71a10d0..f178789bd 100644 --- a/internal/cli/flag.go +++ b/internal/cli/flag.go @@ -79,6 +79,23 @@ func (f StringSliceFlag) RegisterTo(fs *pflag.FlagSet) error { return markHiddenOrDeprecated(fs, f.Name, f.Deprecated, f.Hidden) } +// IntSliceFlag is the flag with int slice value +type IntSliceFlag struct { + Name string + Shorthand string + Usage string + Deprecated string + Hidden bool + + DefValue []int +} + +// RegisterTo register the string slice flag to FlagSet +func (f IntSliceFlag) RegisterTo(fs *pflag.FlagSet) error { + fs.IntSliceP(f.Name, f.Shorthand, f.DefValue, f.Usage) + return markHiddenOrDeprecated(fs, f.Name, f.Deprecated, f.Hidden) +} + func markHiddenOrDeprecated(fs *pflag.FlagSet, name string, deprecated string, hidden bool) error { if len(deprecated) != 0 { // TODO: after totally removed node.sh, change MarkHidden to MarkDeprecated @@ -103,6 +120,8 @@ func getFlagName(flag Flag) string { return f.Name case StringSliceFlag: return f.Name + case IntSliceFlag: + return f.Name } return "" } diff --git a/internal/cli/parse.go b/internal/cli/parse.go index 7b767e6e1..2364267a6 100644 --- a/internal/cli/parse.go +++ b/internal/cli/parse.go @@ -105,6 +105,27 @@ func getStringSliceFlagValue(fs *pflag.FlagSet, flag StringSliceFlag) []string { return val } +// GetIntSliceFlagValue get the int slice value for the given IntSliceFlag from +// the local flags of the cobra command. +func GetIntSliceFlagValue(cmd *cobra.Command, flag IntSliceFlag) []int { + return getIntSliceFlagValue(cmd.Flags(), flag) +} + +// GetIntSlicePersistentFlagValue get the int slice value for the given IntSliceFlag +// from the persistent flags of the cobra command. +func GetIntSlicePersistentFlagValue(cmd *cobra.Command, flag IntSliceFlag) []int { + return getIntSliceFlagValue(cmd.PersistentFlags(), flag) +} + +func getIntSliceFlagValue(fs *pflag.FlagSet, flag IntSliceFlag) []int { + val, err := fs.GetIntSlice(flag.Name) + if err != nil { + handleParseError(err) + return nil + } + return val +} + // IsFlagChanged returns whether the flag has been changed in command func IsFlagChanged(cmd *cobra.Command, flag Flag) bool { name := getFlagName(flag) diff --git a/internal/configs/harmony/harmony.go b/internal/configs/harmony/harmony.go index 95b0926b3..4d9dfa1ea 100644 --- a/internal/configs/harmony/harmony.go +++ b/internal/configs/harmony/harmony.go @@ -87,8 +87,12 @@ type TxPoolConfig struct { } type PprofConfig struct { - Enabled bool - ListenAddr string + Enabled bool + ListenAddr string + Folder string + ProfileNames []string + ProfileIntervals []int `toml:",omitempty"` + ProfileDebugValues []int `toml:",omitempty"` } type LogConfig struct {