From a11fe2d19554ba52bfd0fa2f9ec4344824b3ffb7 Mon Sep 17 00:00:00 2001 From: Andrei Aaron Date: Tue, 19 Sep 2023 00:05:41 +0300 Subject: [PATCH] feat(pprof): add profiling route handler to debug runtime (#1818) (cherry picked from commit 56ddb70f624e7070ad0d3531d498675f9f82c664) Signed-off-by: Alex Stan Signed-off-by: Andrei Aaron Co-authored-by: Alex Stan --- Makefile | 4 +- pkg/api/routes.go | 3 + pkg/debug/constants/consts.go | 1 + pkg/debug/pprof/pprof.go | 153 +++++++++++++++ pkg/debug/pprof/pprof.md | 33 ++++ pkg/debug/pprof/pprof_disabled.go | 18 ++ pkg/debug/pprof/pprof_test.go | 189 +++++++++++++++++++ pkg/extensions/extension_image_trust_test.go | 1 + 8 files changed, 400 insertions(+), 2 deletions(-) create mode 100644 pkg/debug/pprof/pprof.go create mode 100644 pkg/debug/pprof/pprof.md create mode 100644 pkg/debug/pprof/pprof_disabled.go create mode 100644 pkg/debug/pprof/pprof_test.go diff --git a/Makefile b/Makefile index 08c6268b..4ed7a73b 100644 --- a/Makefile +++ b/Makefile @@ -33,8 +33,8 @@ OS ?= $(shell go env GOOS) ARCH ?= $(shell go env GOARCH) BENCH_OUTPUT ?= stdout -ALL_EXTENSIONS = debug,imagetrust,lint,metrics,mgmt,scrub,search,sync,ui,userprefs -EXTENSIONS ?= sync,search,scrub,metrics,lint,ui,mgmt,userprefs,imagetrust +ALL_EXTENSIONS = debug,imagetrust,lint,metrics,mgmt,profile,scrub,search,sync,ui,userprefs +EXTENSIONS ?= sync,search,scrub,metrics,lint,ui,mgmt,profile,userprefs,imagetrust UI_DEPENDENCIES := search,mgmt,userprefs # freebsd/arm64 not supported for pie builds BUILDMODE_FLAGS := -buildmode=pie diff --git a/pkg/api/routes.go b/pkg/api/routes.go index 1c75488e..aecceb8c 100644 --- a/pkg/api/routes.go +++ b/pkg/api/routes.go @@ -39,6 +39,7 @@ import ( apiErr "zotregistry.io/zot/pkg/api/errors" zcommon "zotregistry.io/zot/pkg/common" gqlPlayground "zotregistry.io/zot/pkg/debug/gqlplayground" + pprof "zotregistry.io/zot/pkg/debug/pprof" debug "zotregistry.io/zot/pkg/debug/swagger" ext "zotregistry.io/zot/pkg/extensions" syncConstants "zotregistry.io/zot/pkg/extensions/sync/constants" @@ -178,6 +179,8 @@ func (rh *RouteHandler) SetupRoutes() { debug.SetupSwaggerRoutes(rh.c.Config, rh.c.Router, authHandler, rh.c.Log) // gql playground gqlPlayground.SetupGQLPlaygroundRoutes(prefixedRouter, rh.c.StoreController, rh.c.Log) + // pprof + pprof.SetupPprofRoutes(rh.c.Config, prefixedRouter, authHandler, rh.c.Log) // Preconditions for enabling the actual extension routes are part of extensions themselves ext.SetupMetricsRoutes(rh.c.Config, rh.c.Router, authHandler, rh.c.Log, rh.c.Metrics) diff --git a/pkg/debug/constants/consts.go b/pkg/debug/constants/consts.go index 9faa9427..9b3a2d57 100644 --- a/pkg/debug/constants/consts.go +++ b/pkg/debug/constants/consts.go @@ -3,4 +3,5 @@ package constants const ( Debug = "/_zot/debug" GQLPlaygroundEndpoint = Debug + "/graphql-playground" + ProfilingEndpoint = "/_zot/pprof/" ) diff --git a/pkg/debug/pprof/pprof.go b/pkg/debug/pprof/pprof.go new file mode 100644 index 00000000..ca5d8529 --- /dev/null +++ b/pkg/debug/pprof/pprof.go @@ -0,0 +1,153 @@ +//go:build profile +// +build profile + +package pprof + +import ( + "bytes" + "fmt" + "html" + "io" + "net/http" + "net/http/pprof" + "net/url" + runPprof "runtime/pprof" + "sort" + "strings" + + "github.com/gorilla/mux" + + "zotregistry.io/zot/pkg/api/config" + registryConst "zotregistry.io/zot/pkg/api/constants" + zcommon "zotregistry.io/zot/pkg/common" + "zotregistry.io/zot/pkg/debug/constants" + "zotregistry.io/zot/pkg/log" +) + +type profileEntry struct { + Name string + Href string + Desc string + Count int +} + +var profileDescriptions = map[string]string{ //nolint: gochecknoglobals + "allocs": "A sampling of all past memory allocations", + "block": "Stack traces that led to blocking on synchronization primitives", + "cmdline": "The command line invocation of the current program", + "goroutine": "Stack traces of all current goroutines. Use debug=2 as a query parameter to export in the same format as an unrecovered panic.", //nolint: lll + "heap": "A sampling of memory allocations of live objects. You can specify the gc GET parameter to run GC before taking the heap sample.", //nolint: lll + "mutex": "Stack traces of holders of contended mutexes", + "profile": "CPU profile. You can specify the duration in the seconds GET parameter. After you get the profile file, use the go tool pprof command to investigate the profile.", //nolint: lll + "threadcreate": "Stack traces that led to the creation of new OS threads", + "trace": "A trace of execution of the current program. You can specify the duration in the seconds GET parameter. After you get the trace file, use the go tool trace command to investigate the trace.", //nolint: lll +} + +func SetupPprofRoutes(conf *config.Config, router *mux.Router, authFunc mux.MiddlewareFunc, + log log.Logger, +) { + // If authn/authz are enabled the endpoints for pprof should be available only to admins + pprofRouter := router.PathPrefix(constants.ProfilingEndpoint).Subrouter() + pprofRouter.Use(zcommon.AuthzOnlyAdminsMiddleware(conf)) + pprofRouter.Methods(http.MethodGet).Handler(http.HandlerFunc( + func(w http.ResponseWriter, r *http.Request) { + if name, found := strings.CutPrefix(r.URL.Path, + registryConst.RoutePrefix+constants.ProfilingEndpoint); found { + if name != "" { + switch name { + case "profile": // not available through pprof.Handler + pprof.Profile(w, r) + + return + case "trace": // not available through pprof.Handler + pprof.Trace(w, r) + + return + default: + pprof.Handler(name).ServeHTTP(w, r) + + return + } + } + } + + var profiles []profileEntry + for _, p := range runPprof.Profiles() { + profiles = append(profiles, profileEntry{ + Name: p.Name(), + Href: p.Name(), + Desc: profileDescriptions[p.Name()], + Count: p.Count(), + }) + } + + // Adding other profiles exposed from within this package + for _, p := range []string{"cmdline", "profile", "trace"} { + profiles = append(profiles, profileEntry{ + Name: p, + Href: p, + Desc: profileDescriptions[p], + }) + } + + sort.Slice(profiles, func(i, j int) bool { + return profiles[i].Name < profiles[j].Name + }) + + if err := indexTmplExecute(w, profiles); err != nil { + log.Print(err) + } + })) +} + +func indexTmplExecute(writer io.Writer, profiles []profileEntry) error { + var buff bytes.Buffer + + buff.WriteString(` + +/v2/_zot/pprof/ + + + +/debug/pprof/ +
+

Set debug=1 as a query parameter to export in legacy text format

+
+Types of profiles available: + + +`) + + for _, profile := range profiles { + link := &url.URL{Path: profile.Href, RawQuery: "debug=1"} + fmt.Fprintf(&buff, "\n", + profile.Count, link, html.EscapeString(profile.Name)) + } + + buff.WriteString(`
CountProfile
%d%s
+full goroutine stack dump +
+

+Profile Descriptions: +

    +`) + + for _, profile := range profiles { + fmt.Fprintf(&buff, "
  • %s:
    %s
    • \n", + html.EscapeString(profile.Name), html.EscapeString(profile.Desc)) + } + + buff.WriteString(`
+

+ +`) + + _, err := writer.Write(buff.Bytes()) + + return err +} diff --git a/pkg/debug/pprof/pprof.md b/pkg/debug/pprof/pprof.md new file mode 100644 index 00000000..35d08800 --- /dev/null +++ b/pkg/debug/pprof/pprof.md @@ -0,0 +1,33 @@ +# Profiling in Zot + +This project gives the user the posibility to debug and profile the runtime to find relevant data such as CPU intensive function calls. An in-depth article on profiling in Go can be found [here](https://go.dev/blog/pprof). + +A call to http://localhost:8080/v2/_zot/pprof/ would list the following available profiles, wrapped in an HTML file, with count values prior to change due to the runtime: + +``` +Types of profiles available: +Count Profile +95 allocs +0 block +0 cmdline +11 goroutine +95 heap +0 mutex +0 profile +13 threadcreate +0 trace +full goroutine stack dump +``` + +For example, the following can be used to gather the cpu profile for the amount of seconds specified as a query parameter, and then the results are stored in `cpu.prof` file: +``` +curl -sK -v http://localhost:8080/v2/_zot/pprof/profile?seconds=30 > cpu.prof +``` + +Then, the user can use the `go tool pprof` to analyze the information generated previously in `cpu.prof`. The following command boots up an http server with a GUI and multiple charts that represent the data. +``` +go tool pprof -http=:9090 cpu.prof +``` +A flamegraph example would look like the following: + + \ No newline at end of file diff --git a/pkg/debug/pprof/pprof_disabled.go b/pkg/debug/pprof/pprof_disabled.go new file mode 100644 index 00000000..dfe98a55 --- /dev/null +++ b/pkg/debug/pprof/pprof_disabled.go @@ -0,0 +1,18 @@ +//go:build !profile +// +build !profile + +package pprof + +import ( + "github.com/gorilla/mux" + + "zotregistry.io/zot/pkg/api/config" + "zotregistry.io/zot/pkg/log" //nolint:goimports +) + +func SetupPprofRoutes(conf *config.Config, router *mux.Router, authFunc mux.MiddlewareFunc, + log log.Logger, +) { + log.Warn().Msg("skipping enabling pprof extension because given zot binary " + + "doesn't include this feature, please build a binary that does so") +} diff --git a/pkg/debug/pprof/pprof_test.go b/pkg/debug/pprof/pprof_test.go new file mode 100644 index 00000000..e08f343c --- /dev/null +++ b/pkg/debug/pprof/pprof_test.go @@ -0,0 +1,189 @@ +//go:build profile +// +build profile + +package pprof_test + +import ( + "net/http" + "os" + "testing" + + . "github.com/smartystreets/goconvey/convey" + "gopkg.in/resty.v1" + + "zotregistry.io/zot/pkg/api" + "zotregistry.io/zot/pkg/api/config" + "zotregistry.io/zot/pkg/api/constants" + debugConstants "zotregistry.io/zot/pkg/debug/constants" + "zotregistry.io/zot/pkg/test" +) + +func TestProfilingAuthz(t *testing.T) { + Convey("Make a new controller", t, func() { + port := test.GetFreePort() + baseURL := test.GetBaseURL(port) + adminUsername := "admin" + adminPassword := "admin" + username := "test" + password := "test" + authorizationAllRepos := "**" + + testCreds := test.GetCredString(adminUsername, adminPassword) + + "\n" + test.GetCredString(username, password) + htpasswdPath := test.MakeHtpasswdFileFromString(testCreds) + defer os.Remove(htpasswdPath) + + conf := config.New() + conf.HTTP.Port = port + conf.Storage.RootDirectory = t.TempDir() + + Convey("Test with no access control", func() { + ctlr := api.NewController(conf) + cm := test.NewControllerManager(ctlr) + cm.StartAndWait(port) + defer cm.StopServer() + + // unauthenticated clients should have access to /v2/ + resp, err := resty.R().Get(baseURL + "/v2/") + So(err, ShouldBeNil) + So(resp, ShouldNotBeNil) + So(resp.StatusCode(), ShouldEqual, http.StatusOK) + + // unauthenticated clients should have access to the profiling endpoints + resp, err = resty.R().Get(baseURL + constants.RoutePrefix + debugConstants.ProfilingEndpoint + "trace") + So(err, ShouldBeNil) + So(resp, ShouldNotBeNil) + So(resp.StatusCode(), ShouldEqual, http.StatusOK) + + resp, err = resty.R().SetQueryParam("seconds", "1"). + Get(baseURL + constants.RoutePrefix + debugConstants.ProfilingEndpoint + "profile") + So(err, ShouldBeNil) + So(resp, ShouldNotBeNil) + So(resp.StatusCode(), ShouldEqual, http.StatusOK) + + resp, err = resty.R().Get(baseURL + constants.RoutePrefix + debugConstants.ProfilingEndpoint + "goroutine") + So(err, ShouldBeNil) + So(resp, ShouldNotBeNil) + So(resp.StatusCode(), ShouldEqual, http.StatusOK) + + // test building the index + resp, err = resty.R().Get(baseURL + constants.RoutePrefix + debugConstants.ProfilingEndpoint) + So(err, ShouldBeNil) + So(resp, ShouldNotBeNil) + So(resp.StatusCode(), ShouldEqual, http.StatusOK) + }) + + Convey("Test with authenticated users and no anonymous policy", func() { + conf.HTTP.Auth = &config.AuthConfig{ + HTPasswd: config.AuthHTPasswd{ + Path: htpasswdPath, + }, + } + conf.HTTP.AccessControl = &config.AccessControlConfig{ + Repositories: config.Repositories{ + authorizationAllRepos: config.PolicyGroup{ + Policies: []config.Policy{ + { + Users: []string{username}, + Actions: []string{"read", "create"}, + }, + }, + DefaultPolicy: []string{}, + }, + }, + AdminPolicy: config.Policy{ + Users: []string{adminUsername}, + Actions: []string{}, + }, + } + + ctlr := api.NewController(conf) + cm := test.NewControllerManager(ctlr) + cm.StartAndWait(port) + defer cm.StopServer() + + // unauthenticated clients should not have access to /v2/ + resp, err := resty.R().Get(baseURL + "/v2/") + So(err, ShouldBeNil) + So(resp, ShouldNotBeNil) + So(resp.StatusCode(), ShouldEqual, http.StatusUnauthorized) + + // unauthenticated clients should not have access to the profiling endpoint + resp, err = resty.R().Get(baseURL + constants.RoutePrefix + debugConstants.ProfilingEndpoint + "trace") + So(err, ShouldBeNil) + So(resp, ShouldNotBeNil) + So(resp.StatusCode(), ShouldEqual, http.StatusUnauthorized) + + // authenticated clients without permissions should not have access to the profiling endpoint + resp, err = resty.R().SetBasicAuth(username, password). + Get(baseURL + constants.RoutePrefix + debugConstants.ProfilingEndpoint + "trace") + So(err, ShouldBeNil) + So(resp, ShouldNotBeNil) + So(resp.StatusCode(), ShouldEqual, http.StatusForbidden) + + // authenticated clients with admin permissions should have access to the profiling endpoint + resp, err = resty.R().SetBasicAuth(adminUsername, adminPassword). + Get(baseURL + constants.RoutePrefix + debugConstants.ProfilingEndpoint + "trace") + So(err, ShouldBeNil) + So(resp, ShouldNotBeNil) + So(resp.StatusCode(), ShouldEqual, http.StatusOK) + }) + + Convey("Test with authenticated users and anonymous policy", func() { + conf.HTTP.Auth = &config.AuthConfig{ + HTPasswd: config.AuthHTPasswd{ + Path: htpasswdPath, + }, + } + conf.HTTP.AccessControl = &config.AccessControlConfig{ + Repositories: config.Repositories{ + authorizationAllRepos: config.PolicyGroup{ + Policies: []config.Policy{ + { + Users: []string{username}, + Actions: []string{"read", "create"}, + }, + }, + DefaultPolicy: []string{}, + AnonymousPolicy: []string{"read"}, + }, + }, + AdminPolicy: config.Policy{ + Users: []string{adminUsername}, + Actions: []string{}, + }, + } + + ctlr := api.NewController(conf) + cm := test.NewControllerManager(ctlr) + cm.StartAndWait(port) + defer cm.StopServer() + + // unauthenticated clients should have access to /v2/ + resp, err := resty.R().Get(baseURL + "/v2/") + So(err, ShouldBeNil) + So(resp, ShouldNotBeNil) + So(resp.StatusCode(), ShouldEqual, http.StatusOK) + + // unauthenticated clients should not have access to the profiling endpoint + resp, err = resty.R().Get(baseURL + constants.RoutePrefix + debugConstants.ProfilingEndpoint + "trace") + So(err, ShouldBeNil) + So(resp, ShouldNotBeNil) + So(resp.StatusCode(), ShouldEqual, http.StatusUnauthorized) + + // authenticated clients without permissions should not have access to the profiling endpoint + resp, err = resty.R().SetBasicAuth(username, password). + Get(baseURL + constants.RoutePrefix + debugConstants.ProfilingEndpoint + "trace") + So(err, ShouldBeNil) + So(resp, ShouldNotBeNil) + So(resp.StatusCode(), ShouldEqual, http.StatusForbidden) + + // authenticated clients with admin permissions should have access to the profiling endpoint + resp, err = resty.R().SetBasicAuth(adminUsername, adminPassword). + Get(baseURL + constants.RoutePrefix + debugConstants.ProfilingEndpoint + "trace") + So(err, ShouldBeNil) + So(resp, ShouldNotBeNil) + So(resp.StatusCode(), ShouldEqual, http.StatusOK) + }) + }) +} diff --git a/pkg/extensions/extension_image_trust_test.go b/pkg/extensions/extension_image_trust_test.go index e04bcd1b..19a50dc9 100644 --- a/pkg/extensions/extension_image_trust_test.go +++ b/pkg/extensions/extension_image_trust_test.go @@ -728,6 +728,7 @@ func RunSignatureUploadAndVerificationTests(t *testing.T, cacheDriverParams map[ port := test.GetFreePort() testCreds := test.GetCredString("admin", "admin") + "\n" + test.GetCredString("test", "test") htpasswdPath := test.MakeHtpasswdFileFromString(testCreds) + defer os.Remove(htpasswdPath) conf := config.New() conf.HTTP.Port = port