From e92bca5adf2d0805994bf994b5974a3c8db5b2d6 Mon Sep 17 00:00:00 2001 From: Przemyslaw Kadej Date: Fri, 13 May 2022 23:26:12 +0200 Subject: [PATCH 01/14] PMM-5492 Pprof tool implementation. --- go.mod | 5 +-- go.sum | 2 -- utils/pprof/pprof.go | 72 ++++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 75 insertions(+), 4 deletions(-) create mode 100644 utils/pprof/pprof.go diff --git a/go.mod b/go.mod index c03a7070b8..b15ad1d6aa 100644 --- a/go.mod +++ b/go.mod @@ -3,7 +3,8 @@ module github.com/percona/pmm-managed go 1.18 // Use for local development, but do not commit: -// replace github.com/percona/pmm => ../pmm +replace github.com/percona/pmm => ../pmm + // replace github.com/percona-platform/saas => ../saas // replace github.com/percona-platform/dbaas-api => ../dbaas-api @@ -36,7 +37,7 @@ require ( github.com/minio/minio-go/v7 v7.0.24 github.com/percona-platform/dbaas-api v0.0.0-20220110092915-5aacd784d472 github.com/percona-platform/saas v0.0.0-20220427162947-f9d246ad0f16 - github.com/percona/pmm v0.0.0-20220510110703-cd16c3d93199 + github.com/percona/pmm v0.0.0-20220513204626-f4c3b5528a2e github.com/percona/promconfig v0.2.4-0.20211110115058-98687f586f54 github.com/pkg/errors v0.9.1 github.com/pmezard/go-difflib v1.0.0 diff --git a/go.sum b/go.sum index afa8b8380b..d99fe97fce 100644 --- a/go.sum +++ b/go.sum @@ -466,8 +466,6 @@ github.com/percona-platform/dbaas-api v0.0.0-20220110092915-5aacd784d472 h1:Henk github.com/percona-platform/dbaas-api v0.0.0-20220110092915-5aacd784d472/go.mod h1:WZZ3Hi+lAWCaGWmsrfkkvRQPkIa8n1OZ0s8Su+vbgus= github.com/percona-platform/saas v0.0.0-20220427162947-f9d246ad0f16 h1:0fx16uGtl4MwrBwm9/VSoNEhjL0cXYxS0quEhLthGcc= github.com/percona-platform/saas v0.0.0-20220427162947-f9d246ad0f16/go.mod h1:gFUwaFp6Ugu5qsBwiOVJYbDlzgZ77tmXdXGO7tG5xVI= -github.com/percona/pmm v0.0.0-20220510110703-cd16c3d93199 h1:I4n9DeZypB9AHzejhhsS7koajDYhdkpCN0eNet8mNKw= -github.com/percona/pmm v0.0.0-20220510110703-cd16c3d93199/go.mod h1:k7HS59HPX33tmrSZGiNzUTYuLr0+a49F3BEZ48MAbuo= github.com/percona/promconfig v0.2.4-0.20211110115058-98687f586f54 h1:aI1emmycDTGWKsBdxFPKZqohfBbK4y2ta9G4+RX7gVg= github.com/percona/promconfig v0.2.4-0.20211110115058-98687f586f54/go.mod h1:Y2uXi5QNk71+ceJHuI9poank+0S1kjxd3K105fXKVkg= github.com/pierrec/lz4 v2.0.5+incompatible/go.mod h1:pdkljMzZIN41W+lC3N2tnIh5sFi+IEE17M5jbnwPHcY= diff --git a/utils/pprof/pprof.go b/utils/pprof/pprof.go new file mode 100644 index 0000000000..cfff55775d --- /dev/null +++ b/utils/pprof/pprof.go @@ -0,0 +1,72 @@ +// pmm-managed +// Copyright (C) 2017 Percona LLC +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU Affero General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program 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 Affero General Public License for more details. +// +// You should have received a copy of the GNU Affero General Public License +// along with this program. If not, see . + +package pprof + +import ( + "fmt" + "io" + "runtime" + "runtime/pprof" + "runtime/trace" + "time" +) + +// Profile responds with the pprof-formatted cpu profile. +// Profiling lasts for duration specified in seconds. +func Profile(writer io.Writer, duration int64) error { + if err := pprof.StartCPUProfile(writer); err != nil { + return err + } + + time.Sleep(time.Duration(duration) * time.Second) + pprof.StopCPUProfile() + + return nil +} + +// Trace responds with the execution trace in binary form. +// Tracing lasts for duration specified in seconds. +func Trace(writer io.Writer, duration int64) error { + if err := trace.Start(writer); err != nil { + return err + } + + time.Sleep(time.Duration(duration) * time.Second) + trace.Stop() + + return nil +} + +// Heap responds with the pprof-formatted profile named "heap". +// listing the available profiles. +// You can specify the gc parameter to run gc before taking the heap sample. +func Heap(writer io.Writer, gc bool) error { + debug := 0 + profile := "heap" + + p := pprof.Lookup(profile) + if p == nil { + return fmt.Errorf("profile cannot be found: %s", profile) + } + + if gc { + runtime.GC() + } + + return p.WriteTo(writer, debug) + +} From 882f9aa6dd121c3237b1c505f4cde50a08060b96 Mon Sep 17 00:00:00 2001 From: Przemyslaw Kadej Date: Wed, 18 May 2022 01:06:20 +0200 Subject: [PATCH 02/14] PMM-5492 Pprof in /logs.zip implementation. --- main.go | 14 ++++++++++-- services/supervisord/logs.go | 38 +++++++++++++++++++++++++++---- services/supervisord/logs_test.go | 2 +- 3 files changed, 47 insertions(+), 7 deletions(-) diff --git a/main.go b/main.go index bb5f395a15..435da074da 100644 --- a/main.go +++ b/main.go @@ -111,8 +111,17 @@ func addLogsHandler(mux *http.ServeMux, logs *supervisord.Logs) { l := logrus.WithField("component", "logs.zip") mux.HandleFunc("/logs.zip", func(rw http.ResponseWriter, req *http.Request) { + defaultContextTimeout := 10 + // increase context timeout if pprof query parameter exist in request + pprofQueryParameter, _ := strconv.Atoi(req.FormValue("pprof")) + usePprof := pprofQueryParameter > 0 + if usePprof { + // 60 seconds for profile, 10 seconds for trace, 1 sec for heap + defaultContextTimeout += 71 + } + // fail-safe - ctx, cancel := context.WithTimeout(req.Context(), 10*time.Second) + ctx, cancel := context.WithTimeout(req.Context(), time.Duration(defaultContextTimeout)*time.Second) defer cancel() filename := fmt.Sprintf("pmm-server_%s.zip", time.Now().UTC().Format("2006-01-02_15-04")) @@ -121,9 +130,10 @@ func addLogsHandler(mux *http.ServeMux, logs *supervisord.Logs) { rw.Header().Set(`Content-Disposition`, `attachment; filename="`+filename+`"`) ctx = logger.Set(ctx, "logs") - if err := logs.Zip(ctx, rw); err != nil { + if err := logs.Zip(ctx, rw, usePprof); err != nil { l.Errorf("%+v", err) } + }) } diff --git a/services/supervisord/logs.go b/services/supervisord/logs.go index c03f0c4d92..5357f9407b 100644 --- a/services/supervisord/logs.go +++ b/services/supervisord/logs.go @@ -38,6 +38,7 @@ import ( "golang.org/x/sys/unix" "github.com/percona/pmm-managed/utils/logger" + pprofUtils "github.com/percona/pmm-managed/utils/pprof" ) const ( @@ -69,7 +70,7 @@ func NewLogs(pmmVersion string, pmmUpdateChecker *PMMUpdateChecker) *Logs { } // Zip creates .zip archive with all logs. -func (l *Logs) Zip(ctx context.Context, w io.Writer) error { +func (l *Logs) Zip(ctx context.Context, w io.Writer, pprof bool) error { start := time.Now() log := logger.Get(ctx).WithField("component", "logs") log.WithField("d", time.Since(start).Seconds()).Info("Starting...") @@ -80,12 +81,13 @@ func (l *Logs) Zip(ctx context.Context, w io.Writer) error { zw := zip.NewWriter(w) now := time.Now().UTC() - files := l.files(ctx) + files := l.files(ctx, pprof) log.WithField("d", time.Since(start).Seconds()).Infof("Collected %d files.", len(files)) for _, file := range files { if ctx.Err() != nil { log.WithField("d", time.Since(start).Seconds()).Warnf("%s; skipping the rest of the files", ctx.Err()) + log.WithField("d", time.Since(start).Seconds()).Infof("%s; skipping the rest of the files", ctx.Err()) break } @@ -127,8 +129,8 @@ func (l *Logs) Zip(ctx context.Context, w io.Writer) error { return nil } -// files reads log/config files and returns content. -func (l *Logs) files(ctx context.Context) []fileContent { +// files reads log/config/pprof files and returns content. +func (l *Logs) files(ctx context.Context, pprof bool) []fileContent { files := make([]fileContent, 0, 20) // add logs @@ -214,6 +216,34 @@ func (l *Logs) files(ctx context.Context) []fileContent { Err: err, }) + // add pprof + // TODO: consider replacing writer with bytes[] in pprofUtils + if pprof { + var traceBuf bytes.Buffer + err = pprofUtils.Trace(&traceBuf, 10) + files = append(files, fileContent{ + Name: "pprof/trace.out", + Data: traceBuf.Bytes(), + Err: err, + }) + + var profileBuf bytes.Buffer + err = pprofUtils.Profile(&profileBuf, 60) + files = append(files, fileContent{ + Name: "pprof/profile.pb.gz", + Data: profileBuf.Bytes(), + Err: err, + }) + + var heapBuf bytes.Buffer + err = pprofUtils.Heap(&heapBuf, true) + files = append(files, fileContent{ + Name: "pprof/heap.pb.gz", + Data: heapBuf.Bytes(), + Err: err, + }) + } + sort.Slice(files, func(i, j int) bool { return files[i].Name < files[j].Name }) return files } diff --git a/services/supervisord/logs_test.go b/services/supervisord/logs_test.go index e5b2a2207b..8891f25a49 100644 --- a/services/supervisord/logs_test.go +++ b/services/supervisord/logs_test.go @@ -124,7 +124,7 @@ func TestFiles(t *testing.T) { l := NewLogs("2.4.5", checker) ctx := logger.Set(context.Background(), t.Name()) - files := l.files(ctx) + files := l.files(ctx, false) actual := make([]string, 0, len(files)) for _, f := range files { // present only after update From 366d963a5e826337588cea5f40a94b1927045eaa Mon Sep 17 00:00:00 2001 From: Przemyslaw Kadej Date: Wed, 18 May 2022 23:37:15 +0200 Subject: [PATCH 03/14] PMM-5492 Added pprof_test.go. --- utils/pprof/pprof_test.go | 0 1 file changed, 0 insertions(+), 0 deletions(-) create mode 100644 utils/pprof/pprof_test.go diff --git a/utils/pprof/pprof_test.go b/utils/pprof/pprof_test.go new file mode 100644 index 0000000000..e69de29bb2 From a3c438df44adb8664f32012396e021262444a6c4 Mon Sep 17 00:00:00 2001 From: Przemyslaw Kadej Date: Wed, 18 May 2022 23:38:13 +0200 Subject: [PATCH 04/14] PMM-5492 Added pprof_test.go. --- utils/pprof/pprof_test.go | 74 +++++++++++++++++++++++++++++++++++++++ 1 file changed, 74 insertions(+) diff --git a/utils/pprof/pprof_test.go b/utils/pprof/pprof_test.go index e69de29bb2..012ace7991 100644 --- a/utils/pprof/pprof_test.go +++ b/utils/pprof/pprof_test.go @@ -0,0 +1,74 @@ +// pmm-managed +// Copyright (C) 2017 Percona LLC +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU Affero General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program 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 Affero General Public License for more details. +// +// You should have received a copy of the GNU Affero General Public License +// along with this program. If not, see . + +package pprof + +import ( + "bytes" + "compress/gzip" + "testing" + + "github.com/stretchr/testify/assert" +) + +func TestHeap(t *testing.T) { + t.Parallel() + t.Run("Heap test", func(t *testing.T) { + var heapBuf bytes.Buffer + err := Heap(&heapBuf, true) + + // read gzip + reader, err := gzip.NewReader(&heapBuf) + assert.NoError(t, err) + + var resB bytes.Buffer + _, err = resB.ReadFrom(reader) + assert.NoError(t, err) + assert.True(t, len(resB.Bytes()) > 0) + }) +} + +func TestProfile(t *testing.T) { + t.Parallel() + t.Run("Profile test", func(t *testing.T) { + var profileBuf bytes.Buffer + err := Profile(&profileBuf, 1) + + assert.NoError(t, err) + assert.True(t, len(profileBuf.Bytes()) > 0) + + // read gzip + reader, err := gzip.NewReader(&profileBuf) + assert.NoError(t, err) + + var resB bytes.Buffer + _, err = resB.ReadFrom(reader) + assert.NoError(t, err) + + assert.True(t, len(resB.Bytes()) > 0) + }) +} + +func TestTrace(t *testing.T) { + t.Parallel() + t.Run("Trace test", func(t *testing.T) { + var traceBuf bytes.Buffer + err := Trace(&traceBuf, 1) + + assert.NoError(t, err) + assert.True(t, len(traceBuf.Bytes()) > 0) + }) +} From 683b4db3c29791045853bbc0f8f530b759925fa5 Mon Sep 17 00:00:00 2001 From: Przemyslaw Kadej Date: Thu, 19 May 2022 00:03:24 +0200 Subject: [PATCH 05/14] PMM-5492 Format fix. --- utils/pprof/pprof.go | 1 - 1 file changed, 1 deletion(-) diff --git a/utils/pprof/pprof.go b/utils/pprof/pprof.go index cfff55775d..556696e534 100644 --- a/utils/pprof/pprof.go +++ b/utils/pprof/pprof.go @@ -68,5 +68,4 @@ func Heap(writer io.Writer, gc bool) error { } return p.WriteTo(writer, debug) - } From 214a65694e372f14b247cfbb03e8d1ee70355403 Mon Sep 17 00:00:00 2001 From: Przemyslaw Kadej Date: Thu, 19 May 2022 00:10:01 +0200 Subject: [PATCH 06/14] PMM-5492 Format fix. --- main.go | 1 - 1 file changed, 1 deletion(-) diff --git a/main.go b/main.go index 435da074da..8bca0d7e48 100644 --- a/main.go +++ b/main.go @@ -133,7 +133,6 @@ func addLogsHandler(mux *http.ServeMux, logs *supervisord.Logs) { if err := logs.Zip(ctx, rw, usePprof); err != nil { l.Errorf("%+v", err) } - }) } From b8ddc92b0de53f79bd7255509bbadadb2dff1cb5 Mon Sep 17 00:00:00 2001 From: Przemyslaw Kadej Date: Thu, 19 May 2022 00:26:03 +0200 Subject: [PATCH 07/14] PMM-5492 Tests fix. --- services/supervisord/logs_test.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/services/supervisord/logs_test.go b/services/supervisord/logs_test.go index 8891f25a49..f4e98e78b4 100644 --- a/services/supervisord/logs_test.go +++ b/services/supervisord/logs_test.go @@ -157,7 +157,7 @@ func TestZip(t *testing.T) { ctx := logger.Set(context.Background(), t.Name()) var buf bytes.Buffer - require.NoError(t, l.Zip(ctx, &buf)) + require.NoError(t, l.Zip(ctx, &buf, false)) reader := bytes.NewReader(buf.Bytes()) r, err := zip.NewReader(reader, reader.Size()) require.NoError(t, err) From ea5c6177b74f8e560e678e3fd42adfcc8bf04f49 Mon Sep 17 00:00:00 2001 From: Przemyslaw Kadej Date: Thu, 19 May 2022 00:40:54 +0200 Subject: [PATCH 08/14] PMM-5492 Linter fix. --- utils/pprof/pprof_test.go | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/utils/pprof/pprof_test.go b/utils/pprof/pprof_test.go index 012ace7991..6c7423dd06 100644 --- a/utils/pprof/pprof_test.go +++ b/utils/pprof/pprof_test.go @@ -37,7 +37,7 @@ func TestHeap(t *testing.T) { var resB bytes.Buffer _, err = resB.ReadFrom(reader) assert.NoError(t, err) - assert.True(t, len(resB.Bytes()) > 0) + assert.True(t, len(resB.Bytes()) != 0) }) } @@ -48,7 +48,7 @@ func TestProfile(t *testing.T) { err := Profile(&profileBuf, 1) assert.NoError(t, err) - assert.True(t, len(profileBuf.Bytes()) > 0) + assert.True(t, len(profileBuf.Bytes()) != 0) // read gzip reader, err := gzip.NewReader(&profileBuf) @@ -58,7 +58,7 @@ func TestProfile(t *testing.T) { _, err = resB.ReadFrom(reader) assert.NoError(t, err) - assert.True(t, len(resB.Bytes()) > 0) + assert.True(t, len(resB.Bytes()) != 0) }) } @@ -69,6 +69,6 @@ func TestTrace(t *testing.T) { err := Trace(&traceBuf, 1) assert.NoError(t, err) - assert.True(t, len(traceBuf.Bytes()) > 0) + assert.True(t, len(traceBuf.Bytes()) != 0) }) } From 2f3694184fcc027c17d944ef674a4b710b49102f Mon Sep 17 00:00:00 2001 From: Przemyslaw Kadej Date: Sat, 28 May 2022 00:12:34 +0200 Subject: [PATCH 09/14] PMM-5492 Added configuration support --- main.go | 20 +++++++++++------ services/config/config.go | 4 +++- services/config/pmm-managed.yaml | 3 +++ services/supervisord/logs.go | 25 +++++++++------------ services/supervisord/logs_test.go | 14 ++++++++++-- utils/pprof/pprof.go | 36 +++++++++++++++++++------------ utils/pprof/pprof_config.go | 31 ++++++++++++++++++++++++++ utils/pprof/pprof_test.go | 18 +++++++--------- 8 files changed, 102 insertions(+), 49 deletions(-) create mode 100644 utils/pprof/pprof_config.go diff --git a/main.go b/main.go index 8bca0d7e48..162f422856 100644 --- a/main.go +++ b/main.go @@ -93,6 +93,7 @@ import ( "github.com/percona/pmm-managed/utils/clean" "github.com/percona/pmm-managed/utils/interceptors" "github.com/percona/pmm-managed/utils/logger" + "github.com/percona/pmm-managed/utils/pprof" ) const ( @@ -110,18 +111,23 @@ const ( func addLogsHandler(mux *http.ServeMux, logs *supervisord.Logs) { l := logrus.WithField("component", "logs.zip") + cfg := config.NewService() + if err := cfg.Load(); err != nil { + l.Panicf("Failed to load config: %+v", err) + } + mux.HandleFunc("/logs.zip", func(rw http.ResponseWriter, req *http.Request) { - defaultContextTimeout := 10 + contextTimeout := 10 * time.Second // increase context timeout if pprof query parameter exist in request pprofQueryParameter, _ := strconv.Atoi(req.FormValue("pprof")) - usePprof := pprofQueryParameter > 0 - if usePprof { - // 60 seconds for profile, 10 seconds for trace, 1 sec for heap - defaultContextTimeout += 71 + var pprofSettings *pprof.Config + if pprofQueryParameter > 0 { + contextTimeout += cfg.Config.Services.Pprof.ProfileDuration + cfg.Config.Services.Pprof.TraceDuration + pprofSettings = &cfg.Config.Services.Pprof } // fail-safe - ctx, cancel := context.WithTimeout(req.Context(), time.Duration(defaultContextTimeout)*time.Second) + ctx, cancel := context.WithTimeout(req.Context(), contextTimeout) defer cancel() filename := fmt.Sprintf("pmm-server_%s.zip", time.Now().UTC().Format("2006-01-02_15-04")) @@ -130,7 +136,7 @@ func addLogsHandler(mux *http.ServeMux, logs *supervisord.Logs) { rw.Header().Set(`Content-Disposition`, `attachment; filename="`+filename+`"`) ctx = logger.Set(ctx, "logs") - if err := logs.Zip(ctx, rw, usePprof); err != nil { + if err := logs.Zip(ctx, rw, pprofSettings); err != nil { l.Errorf("%+v", err) } }) diff --git a/services/config/config.go b/services/config/config.go index eda8a0246d..8e95661903 100644 --- a/services/config/config.go +++ b/services/config/config.go @@ -28,6 +28,7 @@ import ( "github.com/percona/pmm-managed/services/platform" "github.com/percona/pmm-managed/services/telemetry" + "github.com/percona/pmm-managed/utils/pprof" ) const ( @@ -49,6 +50,7 @@ type Config struct { Services struct { Platform platform.Config `yaml:"platform"` Telemetry telemetry.ServiceConfig `yaml:"telemetry"` + Pprof pprof.Config `yaml:"pprof"` } `yaml:"services"` } @@ -94,7 +96,7 @@ func (s *Service) Load() error { if err := cfg.Services.Telemetry.Init(s.l); err != nil { return err } - + cfg.Services.Pprof.Init() s.Config = cfg return nil diff --git a/services/config/pmm-managed.yaml b/services/config/pmm-managed.yaml index f80c1d98d0..1284453042 100644 --- a/services/config/pmm-managed.yaml +++ b/services/config/pmm-managed.yaml @@ -32,3 +32,6 @@ services: retry_backoff_env: "PERCONA_TEST_TELEMETRY_RETRY_BACKOFF" retry_count: 20 send_timeout: 5s + pprof: + profile_duration: 30s + trace_duration: 10s \ No newline at end of file diff --git a/services/supervisord/logs.go b/services/supervisord/logs.go index 5357f9407b..90556ccbbd 100644 --- a/services/supervisord/logs.go +++ b/services/supervisord/logs.go @@ -70,7 +70,7 @@ func NewLogs(pmmVersion string, pmmUpdateChecker *PMMUpdateChecker) *Logs { } // Zip creates .zip archive with all logs. -func (l *Logs) Zip(ctx context.Context, w io.Writer, pprof bool) error { +func (l *Logs) Zip(ctx context.Context, w io.Writer, pprofSettings *pprofUtils.Config) error { start := time.Now() log := logger.Get(ctx).WithField("component", "logs") log.WithField("d", time.Since(start).Seconds()).Info("Starting...") @@ -81,13 +81,12 @@ func (l *Logs) Zip(ctx context.Context, w io.Writer, pprof bool) error { zw := zip.NewWriter(w) now := time.Now().UTC() - files := l.files(ctx, pprof) + files := l.files(ctx, pprofSettings) log.WithField("d", time.Since(start).Seconds()).Infof("Collected %d files.", len(files)) for _, file := range files { if ctx.Err() != nil { log.WithField("d", time.Since(start).Seconds()).Warnf("%s; skipping the rest of the files", ctx.Err()) - log.WithField("d", time.Since(start).Seconds()).Infof("%s; skipping the rest of the files", ctx.Err()) break } @@ -130,7 +129,7 @@ func (l *Logs) Zip(ctx context.Context, w io.Writer, pprof bool) error { } // files reads log/config/pprof files and returns content. -func (l *Logs) files(ctx context.Context, pprof bool) []fileContent { +func (l *Logs) files(ctx context.Context, pprofSettings *pprofUtils.Config) []fileContent { files := make([]fileContent, 0, 20) // add logs @@ -217,29 +216,25 @@ func (l *Logs) files(ctx context.Context, pprof bool) []fileContent { }) // add pprof - // TODO: consider replacing writer with bytes[] in pprofUtils - if pprof { - var traceBuf bytes.Buffer - err = pprofUtils.Trace(&traceBuf, 10) + if pprofSettings != nil { + traceBytes, err := pprofUtils.Trace(pprofSettings.TraceDuration) files = append(files, fileContent{ Name: "pprof/trace.out", - Data: traceBuf.Bytes(), + Data: traceBytes, Err: err, }) - var profileBuf bytes.Buffer - err = pprofUtils.Profile(&profileBuf, 60) + profileBytes, err := pprofUtils.Profile(pprofSettings.ProfileDuration) files = append(files, fileContent{ Name: "pprof/profile.pb.gz", - Data: profileBuf.Bytes(), + Data: profileBytes, Err: err, }) - var heapBuf bytes.Buffer - err = pprofUtils.Heap(&heapBuf, true) + heapBytes, err := pprofUtils.Heap(true) files = append(files, fileContent{ Name: "pprof/heap.pb.gz", - Data: heapBuf.Bytes(), + Data: heapBytes, Err: err, }) } diff --git a/services/supervisord/logs_test.go b/services/supervisord/logs_test.go index f4e98e78b4..63a61d07b2 100644 --- a/services/supervisord/logs_test.go +++ b/services/supervisord/logs_test.go @@ -34,6 +34,7 @@ import ( "github.com/stretchr/testify/require" "github.com/percona/pmm-managed/utils/logger" + "github.com/percona/pmm-managed/utils/pprof" ) var commonExpectedFiles = []string{ @@ -55,6 +56,9 @@ var commonExpectedFiles = []string{ "pmm.conf", "pmm.ini", "postgresql.log", + "pprof/heap.pb.gz", + "pprof/profile.pb.gz", + "pprof/trace.out", "qan-api2.ini", "qan-api2.log", "supervisorctl_status.log", @@ -124,7 +128,10 @@ func TestFiles(t *testing.T) { l := NewLogs("2.4.5", checker) ctx := logger.Set(context.Background(), t.Name()) - files := l.files(ctx, false) + files := l.files(ctx, &pprof.Config{ + ProfileDuration: 1 * time.Second, + TraceDuration: 1 * time.Second, + }) actual := make([]string, 0, len(files)) for _, f := range files { // present only after update @@ -157,7 +164,10 @@ func TestZip(t *testing.T) { ctx := logger.Set(context.Background(), t.Name()) var buf bytes.Buffer - require.NoError(t, l.Zip(ctx, &buf, false)) + require.NoError(t, l.Zip(ctx, &buf, &pprof.Config{ + ProfileDuration: 1 * time.Second, + TraceDuration: 1 * time.Second, + })) reader := bytes.NewReader(buf.Bytes()) r, err := zip.NewReader(reader, reader.Size()) require.NoError(t, err) diff --git a/utils/pprof/pprof.go b/utils/pprof/pprof.go index 556696e534..de1486daaf 100644 --- a/utils/pprof/pprof.go +++ b/utils/pprof/pprof.go @@ -17,8 +17,8 @@ package pprof import ( + "bytes" "fmt" - "io" "runtime" "runtime/pprof" "runtime/trace" @@ -27,45 +27,53 @@ import ( // Profile responds with the pprof-formatted cpu profile. // Profiling lasts for duration specified in seconds. -func Profile(writer io.Writer, duration int64) error { - if err := pprof.StartCPUProfile(writer); err != nil { - return err +func Profile(duration time.Duration) ([]byte, error) { + var profileBuf bytes.Buffer + if err := pprof.StartCPUProfile(&profileBuf); err != nil { + return nil, err } - time.Sleep(time.Duration(duration) * time.Second) + time.Sleep(duration) pprof.StopCPUProfile() - return nil + return profileBuf.Bytes(), nil } // Trace responds with the execution trace in binary form. // Tracing lasts for duration specified in seconds. -func Trace(writer io.Writer, duration int64) error { - if err := trace.Start(writer); err != nil { - return err +func Trace(duration time.Duration) ([]byte, error) { + var traceBuf bytes.Buffer + if err := trace.Start(&traceBuf); err != nil { + return nil, err } - time.Sleep(time.Duration(duration) * time.Second) + time.Sleep(duration) trace.Stop() - return nil + return traceBuf.Bytes(), nil } // Heap responds with the pprof-formatted profile named "heap". // listing the available profiles. // You can specify the gc parameter to run gc before taking the heap sample. -func Heap(writer io.Writer, gc bool) error { +func Heap(gc bool) ([]byte, error) { + var heapBuf bytes.Buffer debug := 0 profile := "heap" p := pprof.Lookup(profile) if p == nil { - return fmt.Errorf("profile cannot be found: %s", profile) + return nil, fmt.Errorf("profile cannot be found: %s", profile) } if gc { runtime.GC() } - return p.WriteTo(writer, debug) + err := p.WriteTo(&heapBuf, debug) + if err != nil { + return nil, err + } + + return heapBuf.Bytes(), nil } diff --git a/utils/pprof/pprof_config.go b/utils/pprof/pprof_config.go new file mode 100644 index 0000000000..03709795ed --- /dev/null +++ b/utils/pprof/pprof_config.go @@ -0,0 +1,31 @@ +// pmm-managed +// Copyright (C) 2017 Percona LLC +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU Affero General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program 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 Affero General Public License for more details. +// +// You should have received a copy of the GNU Affero General Public License +// along with this program. If not, see . + +package pprof + +import ( + "time" +) + +// Config pprof settings. +type Config struct { + ProfileDuration time.Duration `yaml:"profile_duration"` //nolint:tagliatelle + TraceDuration time.Duration `yaml:"trace_duration"` //nolint:tagliatelle +} + +// Init pprof config init. +func (c *Config) Init() { +} diff --git a/utils/pprof/pprof_test.go b/utils/pprof/pprof_test.go index 6c7423dd06..6bee9b0ee7 100644 --- a/utils/pprof/pprof_test.go +++ b/utils/pprof/pprof_test.go @@ -20,6 +20,7 @@ import ( "bytes" "compress/gzip" "testing" + "time" "github.com/stretchr/testify/assert" ) @@ -27,11 +28,10 @@ import ( func TestHeap(t *testing.T) { t.Parallel() t.Run("Heap test", func(t *testing.T) { - var heapBuf bytes.Buffer - err := Heap(&heapBuf, true) + heapBytes, err := Heap(true) // read gzip - reader, err := gzip.NewReader(&heapBuf) + reader, err := gzip.NewReader(bytes.NewBuffer(heapBytes)) assert.NoError(t, err) var resB bytes.Buffer @@ -44,14 +44,13 @@ func TestHeap(t *testing.T) { func TestProfile(t *testing.T) { t.Parallel() t.Run("Profile test", func(t *testing.T) { - var profileBuf bytes.Buffer - err := Profile(&profileBuf, 1) + profileBytes, err := Profile(1 * time.Second) assert.NoError(t, err) - assert.True(t, len(profileBuf.Bytes()) != 0) + assert.True(t, len(profileBytes) != 0) // read gzip - reader, err := gzip.NewReader(&profileBuf) + reader, err := gzip.NewReader(bytes.NewBuffer(profileBytes)) assert.NoError(t, err) var resB bytes.Buffer @@ -65,10 +64,9 @@ func TestProfile(t *testing.T) { func TestTrace(t *testing.T) { t.Parallel() t.Run("Trace test", func(t *testing.T) { - var traceBuf bytes.Buffer - err := Trace(&traceBuf, 1) + traceBytes, err := Trace(1 * time.Second) assert.NoError(t, err) - assert.True(t, len(traceBuf.Bytes()) != 0) + assert.True(t, len(traceBytes) != 0) }) } From a28413ef86fc954634af96ccd0182e66949fec0b Mon Sep 17 00:00:00 2001 From: Przemyslaw Kadej Date: Tue, 7 Jun 2022 23:27:48 +0200 Subject: [PATCH 10/14] PMM-5492 Code review adjustments. --- main.go | 17 ++++++++++++----- services/config/pmm-managed.yaml | 3 --- services/supervisord/logs.go | 8 ++++---- utils/pprof/pprof_test.go | 8 ++++---- 4 files changed, 20 insertions(+), 16 deletions(-) diff --git a/main.go b/main.go index fbc07de20c..f640031411 100644 --- a/main.go +++ b/main.go @@ -108,6 +108,10 @@ const ( cleanInterval = 10 * time.Minute cleanOlderThan = 30 * time.Minute + + defaultContextTimeout = 10 * time.Second + pProfProfileDuration = 30 * time.Second + pProfTraceDuration = 10 * time.Second ) func addLogsHandler(mux *http.ServeMux, logs *supervisord.Logs) { @@ -119,13 +123,16 @@ func addLogsHandler(mux *http.ServeMux, logs *supervisord.Logs) { } mux.HandleFunc("/logs.zip", func(rw http.ResponseWriter, req *http.Request) { - contextTimeout := 10 * time.Second + contextTimeout := defaultContextTimeout // increase context timeout if pprof query parameter exist in request pprofQueryParameter, _ := strconv.Atoi(req.FormValue("pprof")) - var pprofSettings *pprof.Config + var pprofConfig *pprof.Config if pprofQueryParameter > 0 { - contextTimeout += cfg.Config.Services.Pprof.ProfileDuration + cfg.Config.Services.Pprof.TraceDuration - pprofSettings = &cfg.Config.Services.Pprof + contextTimeout += pProfProfileDuration + pProfTraceDuration + pprofConfig = &pprof.Config{ + ProfileDuration: pProfProfileDuration, + TraceDuration: pProfTraceDuration, + } } // fail-safe @@ -138,7 +145,7 @@ func addLogsHandler(mux *http.ServeMux, logs *supervisord.Logs) { rw.Header().Set(`Content-Disposition`, `attachment; filename="`+filename+`"`) ctx = logger.Set(ctx, "logs") - if err := logs.Zip(ctx, rw, pprofSettings); err != nil { + if err := logs.Zip(ctx, rw, pprofConfig); err != nil { l.Errorf("%+v", err) } }) diff --git a/services/config/pmm-managed.yaml b/services/config/pmm-managed.yaml index 1284453042..f80c1d98d0 100644 --- a/services/config/pmm-managed.yaml +++ b/services/config/pmm-managed.yaml @@ -32,6 +32,3 @@ services: retry_backoff_env: "PERCONA_TEST_TELEMETRY_RETRY_BACKOFF" retry_count: 20 send_timeout: 5s - pprof: - profile_duration: 30s - trace_duration: 10s \ No newline at end of file diff --git a/services/supervisord/logs.go b/services/supervisord/logs.go index 90556ccbbd..bd70cd4cd5 100644 --- a/services/supervisord/logs.go +++ b/services/supervisord/logs.go @@ -129,7 +129,7 @@ func (l *Logs) Zip(ctx context.Context, w io.Writer, pprofSettings *pprofUtils.C } // files reads log/config/pprof files and returns content. -func (l *Logs) files(ctx context.Context, pprofSettings *pprofUtils.Config) []fileContent { +func (l *Logs) files(ctx context.Context, pprofConfig *pprofUtils.Config) []fileContent { files := make([]fileContent, 0, 20) // add logs @@ -216,15 +216,15 @@ func (l *Logs) files(ctx context.Context, pprofSettings *pprofUtils.Config) []fi }) // add pprof - if pprofSettings != nil { - traceBytes, err := pprofUtils.Trace(pprofSettings.TraceDuration) + if pprofConfig != nil { + traceBytes, err := pprofUtils.Trace(pprofConfig.TraceDuration) files = append(files, fileContent{ Name: "pprof/trace.out", Data: traceBytes, Err: err, }) - profileBytes, err := pprofUtils.Profile(pprofSettings.ProfileDuration) + profileBytes, err := pprofUtils.Profile(pprofConfig.ProfileDuration) files = append(files, fileContent{ Name: "pprof/profile.pb.gz", Data: profileBytes, diff --git a/utils/pprof/pprof_test.go b/utils/pprof/pprof_test.go index 6bee9b0ee7..5b037dccab 100644 --- a/utils/pprof/pprof_test.go +++ b/utils/pprof/pprof_test.go @@ -37,7 +37,7 @@ func TestHeap(t *testing.T) { var resB bytes.Buffer _, err = resB.ReadFrom(reader) assert.NoError(t, err) - assert.True(t, len(resB.Bytes()) != 0) + assert.NotEmpty(t, resB.Bytes()) }) } @@ -47,7 +47,7 @@ func TestProfile(t *testing.T) { profileBytes, err := Profile(1 * time.Second) assert.NoError(t, err) - assert.True(t, len(profileBytes) != 0) + assert.NotEmpty(t, profileBytes) // read gzip reader, err := gzip.NewReader(bytes.NewBuffer(profileBytes)) @@ -57,7 +57,7 @@ func TestProfile(t *testing.T) { _, err = resB.ReadFrom(reader) assert.NoError(t, err) - assert.True(t, len(resB.Bytes()) != 0) + assert.NotEmpty(t, resB.Bytes()) }) } @@ -67,6 +67,6 @@ func TestTrace(t *testing.T) { traceBytes, err := Trace(1 * time.Second) assert.NoError(t, err) - assert.True(t, len(traceBytes) != 0) + assert.NotEmpty(t, traceBytes) }) } From 28e4406fb65b737e588bfb70c1bc185f14fd30ce Mon Sep 17 00:00:00 2001 From: Przemyslaw Kadej Date: Tue, 7 Jun 2022 23:31:22 +0200 Subject: [PATCH 11/14] PMM-5492 Code review adjustments. --- main.go | 5 ----- 1 file changed, 5 deletions(-) diff --git a/main.go b/main.go index f640031411..fcc785d684 100644 --- a/main.go +++ b/main.go @@ -117,11 +117,6 @@ const ( func addLogsHandler(mux *http.ServeMux, logs *supervisord.Logs) { l := logrus.WithField("component", "logs.zip") - cfg := config.NewService() - if err := cfg.Load(); err != nil { - l.Panicf("Failed to load config: %+v", err) - } - mux.HandleFunc("/logs.zip", func(rw http.ResponseWriter, req *http.Request) { contextTimeout := defaultContextTimeout // increase context timeout if pprof query parameter exist in request From 291869e1d71a3c5d2315e85f9d8b6af54bd7a047 Mon Sep 17 00:00:00 2001 From: Przemyslaw Kadej Date: Tue, 7 Jun 2022 23:33:18 +0200 Subject: [PATCH 12/14] PMM-5492 Code review adjustments. --- services/supervisord/logs.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/services/supervisord/logs.go b/services/supervisord/logs.go index bd70cd4cd5..81901ebeeb 100644 --- a/services/supervisord/logs.go +++ b/services/supervisord/logs.go @@ -70,7 +70,7 @@ func NewLogs(pmmVersion string, pmmUpdateChecker *PMMUpdateChecker) *Logs { } // Zip creates .zip archive with all logs. -func (l *Logs) Zip(ctx context.Context, w io.Writer, pprofSettings *pprofUtils.Config) error { +func (l *Logs) Zip(ctx context.Context, w io.Writer, pprofConfig *pprofUtils.Config) error { start := time.Now() log := logger.Get(ctx).WithField("component", "logs") log.WithField("d", time.Since(start).Seconds()).Info("Starting...") @@ -81,7 +81,7 @@ func (l *Logs) Zip(ctx context.Context, w io.Writer, pprofSettings *pprofUtils.C zw := zip.NewWriter(w) now := time.Now().UTC() - files := l.files(ctx, pprofSettings) + files := l.files(ctx, pprofConfig) log.WithField("d", time.Since(start).Seconds()).Infof("Collected %d files.", len(files)) for _, file := range files { From 27856c8edf9119134ff947f4b1fa257b260b6cb9 Mon Sep 17 00:00:00 2001 From: Przemyslaw Kadej Date: Sat, 11 Jun 2022 23:08:01 +0200 Subject: [PATCH 13/14] PMM-5492 Code review adjustments. --- main.go | 7 +++-- services/config/config.go | 3 -- services/supervisord/logs.go | 56 +++++++++++++++++++++++------------- 3 files changed, 41 insertions(+), 25 deletions(-) diff --git a/main.go b/main.go index f7f1029d01..f4144688f5 100644 --- a/main.go +++ b/main.go @@ -120,9 +120,12 @@ func addLogsHandler(mux *http.ServeMux, logs *supervisord.Logs) { mux.HandleFunc("/logs.zip", func(rw http.ResponseWriter, req *http.Request) { contextTimeout := defaultContextTimeout // increase context timeout if pprof query parameter exist in request - pprofQueryParameter, _ := strconv.Atoi(req.FormValue("pprof")) + pprofQueryParameter, err := strconv.ParseBool(req.FormValue("pprof")) + if err != nil { + l.Debug("Unable to read 'pprof' query param. Using default: pprof=false") + } var pprofConfig *pprof.Config - if pprofQueryParameter > 0 { + if pprofQueryParameter { contextTimeout += pProfProfileDuration + pProfTraceDuration pprofConfig = &pprof.Config{ ProfileDuration: pProfProfileDuration, diff --git a/services/config/config.go b/services/config/config.go index 8e95661903..023781327e 100644 --- a/services/config/config.go +++ b/services/config/config.go @@ -28,7 +28,6 @@ import ( "github.com/percona/pmm-managed/services/platform" "github.com/percona/pmm-managed/services/telemetry" - "github.com/percona/pmm-managed/utils/pprof" ) const ( @@ -50,7 +49,6 @@ type Config struct { Services struct { Platform platform.Config `yaml:"platform"` Telemetry telemetry.ServiceConfig `yaml:"telemetry"` - Pprof pprof.Config `yaml:"pprof"` } `yaml:"services"` } @@ -96,7 +94,6 @@ func (s *Service) Load() error { if err := cfg.Services.Telemetry.Init(s.l); err != nil { return err } - cfg.Services.Pprof.Init() s.Config = cfg return nil diff --git a/services/supervisord/logs.go b/services/supervisord/logs.go index 81901ebeeb..eeff8300c7 100644 --- a/services/supervisord/logs.go +++ b/services/supervisord/logs.go @@ -31,6 +31,7 @@ import ( "os/exec" "path/filepath" "sort" + "sync" "time" "github.com/percona/pmm/utils/pdeathsig" @@ -217,26 +218,41 @@ func (l *Logs) files(ctx context.Context, pprofConfig *pprofUtils.Config) []file // add pprof if pprofConfig != nil { - traceBytes, err := pprofUtils.Trace(pprofConfig.TraceDuration) - files = append(files, fileContent{ - Name: "pprof/trace.out", - Data: traceBytes, - Err: err, - }) - - profileBytes, err := pprofUtils.Profile(pprofConfig.ProfileDuration) - files = append(files, fileContent{ - Name: "pprof/profile.pb.gz", - Data: profileBytes, - Err: err, - }) - - heapBytes, err := pprofUtils.Heap(true) - files = append(files, fileContent{ - Name: "pprof/heap.pb.gz", - Data: heapBytes, - Err: err, - }) + var wg sync.WaitGroup + wg.Add(1) + go func() { + defer wg.Done() + traceBytes, err := pprofUtils.Trace(pprofConfig.TraceDuration) + files = append(files, fileContent{ + Name: "pprof/trace.out", + Data: traceBytes, + Err: err, + }) + }() + + wg.Add(1) + go func() { + defer wg.Done() + profileBytes, err := pprofUtils.Profile(pprofConfig.ProfileDuration) + files = append(files, fileContent{ + Name: "pprof/profile.pb.gz", + Data: profileBytes, + Err: err, + }) + }() + + wg.Add(1) + go func() { + defer wg.Done() + heapBytes, err := pprofUtils.Heap(true) + files = append(files, fileContent{ + Name: "pprof/heap.pb.gz", + Data: heapBytes, + Err: err, + }) + }() + + wg.Wait() } sort.Slice(files, func(i, j int) bool { return files[i].Name < files[j].Name }) From 3d5d295fea788b10133878ba129377c10a95b568 Mon Sep 17 00:00:00 2001 From: Przemyslaw Kadej Date: Thu, 16 Jun 2022 10:48:03 +0200 Subject: [PATCH 14/14] PMM-5492 Test fixes. --- services/supervisord/logs_test.go | 14 ++------------ 1 file changed, 2 insertions(+), 12 deletions(-) diff --git a/services/supervisord/logs_test.go b/services/supervisord/logs_test.go index 63a61d07b2..cac791bac8 100644 --- a/services/supervisord/logs_test.go +++ b/services/supervisord/logs_test.go @@ -34,7 +34,6 @@ import ( "github.com/stretchr/testify/require" "github.com/percona/pmm-managed/utils/logger" - "github.com/percona/pmm-managed/utils/pprof" ) var commonExpectedFiles = []string{ @@ -56,9 +55,6 @@ var commonExpectedFiles = []string{ "pmm.conf", "pmm.ini", "postgresql.log", - "pprof/heap.pb.gz", - "pprof/profile.pb.gz", - "pprof/trace.out", "qan-api2.ini", "qan-api2.log", "supervisorctl_status.log", @@ -128,10 +124,7 @@ func TestFiles(t *testing.T) { l := NewLogs("2.4.5", checker) ctx := logger.Set(context.Background(), t.Name()) - files := l.files(ctx, &pprof.Config{ - ProfileDuration: 1 * time.Second, - TraceDuration: 1 * time.Second, - }) + files := l.files(ctx, nil) actual := make([]string, 0, len(files)) for _, f := range files { // present only after update @@ -164,10 +157,7 @@ func TestZip(t *testing.T) { ctx := logger.Set(context.Background(), t.Name()) var buf bytes.Buffer - require.NoError(t, l.Zip(ctx, &buf, &pprof.Config{ - ProfileDuration: 1 * time.Second, - TraceDuration: 1 * time.Second, - })) + require.NoError(t, l.Zip(ctx, &buf, nil)) reader := bytes.NewReader(buf.Bytes()) r, err := zip.NewReader(reader, reader.Size()) require.NoError(t, err)