profiling for 'zrok enable' controller backend (#550)

This commit is contained in:
Michael Quigley 2024-01-29 08:37:25 -05:00
parent 8d88e32d91
commit 665b6f5b6b
No known key found for this signature in database
GPG Key ID: 9B60314A9DD20A62

View File

@ -11,6 +11,7 @@ import (
"github.com/openziti/zrok/rest_server_zrok/operations/environment" "github.com/openziti/zrok/rest_server_zrok/operations/environment"
"github.com/pkg/errors" "github.com/pkg/errors"
"github.com/sirupsen/logrus" "github.com/sirupsen/logrus"
"time"
) )
type enableHandler struct{} type enableHandler struct{}
@ -20,6 +21,8 @@ func newEnableHandler() *enableHandler {
} }
func (h *enableHandler) Handle(params environment.EnableParams, principal *rest_model_zrok.Principal) middleware.Responder { func (h *enableHandler) Handle(params environment.EnableParams, principal *rest_model_zrok.Principal) middleware.Responder {
start := time.Now()
// start transaction early; if it fails, don't bother creating ziti resources // start transaction early; if it fails, don't bother creating ziti resources
trx, err := str.Begin() trx, err := str.Begin()
if err != nil { if err != nil {
@ -27,42 +30,56 @@ func (h *enableHandler) Handle(params environment.EnableParams, principal *rest_
return environment.NewEnableInternalServerError() return environment.NewEnableInternalServerError()
} }
defer func() { _ = trx.Rollback() }() defer func() { _ = trx.Rollback() }()
finishTrx := time.Since(start)
startLimits := time.Now()
if err := h.checkLimits(principal, trx); err != nil { if err := h.checkLimits(principal, trx); err != nil {
logrus.Errorf("limits error for user '%v': %v", principal.Email, err) logrus.Errorf("limits error for user '%v': %v", principal.Email, err)
return environment.NewEnableUnauthorized() return environment.NewEnableUnauthorized()
} }
finishLimits := time.Since(startLimits)
startClient := time.Now()
client, err := zrokEdgeSdk.Client(cfg.Ziti) client, err := zrokEdgeSdk.Client(cfg.Ziti)
if err != nil { if err != nil {
logrus.Errorf("error getting edge client for user '%v': %v", principal.Email, err) logrus.Errorf("error getting edge client for user '%v': %v", principal.Email, err)
return environment.NewEnableInternalServerError() return environment.NewEnableInternalServerError()
} }
finishClient := time.Since(startClient)
startToken := time.Now()
uniqueToken, err := createShareToken() uniqueToken, err := createShareToken()
if err != nil { if err != nil {
logrus.Errorf("error creating unique identity token for user '%v': %v", principal.Email, err) logrus.Errorf("error creating unique identity token for user '%v': %v", principal.Email, err)
return environment.NewEnableInternalServerError() return environment.NewEnableInternalServerError()
} }
finishToken := time.Since(startToken)
startIdentity := time.Now()
ident, err := zrokEdgeSdk.CreateEnvironmentIdentity(uniqueToken, principal.Email, params.Body.Description, client) ident, err := zrokEdgeSdk.CreateEnvironmentIdentity(uniqueToken, principal.Email, params.Body.Description, client)
if err != nil { if err != nil {
logrus.Errorf("error creating environment identity for user '%v': %v", principal.Email, err) logrus.Errorf("error creating environment identity for user '%v': %v", principal.Email, err)
return environment.NewEnableInternalServerError() return environment.NewEnableInternalServerError()
} }
finishIdentity := time.Since(startIdentity)
startEnroll := time.Now()
envZId := ident.Payload.Data.ID envZId := ident.Payload.Data.ID
cfg, err := zrokEdgeSdk.EnrollIdentity(envZId, client) cfg, err := zrokEdgeSdk.EnrollIdentity(envZId, client)
if err != nil { if err != nil {
logrus.Errorf("error enrolling environment identity for user '%v': %v", principal.Email, err) logrus.Errorf("error enrolling environment identity for user '%v': %v", principal.Email, err)
return environment.NewEnableInternalServerError() return environment.NewEnableInternalServerError()
} }
finishEnroll := time.Since(startEnroll)
startERP := time.Now()
if err := zrokEdgeSdk.CreateEdgeRouterPolicy(envZId, envZId, client); err != nil { if err := zrokEdgeSdk.CreateEdgeRouterPolicy(envZId, envZId, client); err != nil {
logrus.Errorf("error creating edge router policy for user '%v': %v", principal.Email, err) logrus.Errorf("error creating edge router policy for user '%v': %v", principal.Email, err)
return environment.NewEnableInternalServerError() return environment.NewEnableInternalServerError()
} }
finishERP := time.Since(startERP)
startStore := time.Now()
envId, err := str.CreateEnvironment(int(principal.ID), &store.Environment{ envId, err := str.CreateEnvironment(int(principal.ID), &store.Environment{
Description: params.Body.Description, Description: params.Body.Description,
Host: params.Body.Host, Host: params.Body.Host,
@ -74,7 +91,9 @@ func (h *enableHandler) Handle(params environment.EnableParams, principal *rest_
_ = trx.Rollback() _ = trx.Rollback()
return environment.NewEnableInternalServerError() return environment.NewEnableInternalServerError()
} }
finishStore := time.Since(startStore)
startCommit := time.Now()
if err := trx.Commit(); err != nil { if err := trx.Commit(); err != nil {
logrus.Errorf("error committing for user '%v': %v", principal.Email, err) logrus.Errorf("error committing for user '%v': %v", principal.Email, err)
return environment.NewEnableInternalServerError() return environment.NewEnableInternalServerError()
@ -94,6 +113,12 @@ func (h *enableHandler) Handle(params environment.EnableParams, principal *rest_
} }
resp.Payload.Cfg = out.String() resp.Payload.Cfg = out.String()
finishCommit := time.Since(startCommit)
finish := time.Since(start)
logrus.Infof("finishTrx = %v, finishLimits = %v, finishClient = %v, finishToken = %v, finishIdentity = %v, finishEnroll = %v, finishERP = %v, finishStore = %v, finishCommit = %v, finish = %v",
finishTrx, finishLimits, finishClient, finishToken, finishIdentity, finishEnroll, finishERP, finishStore, finishCommit, finish)
return resp return resp
} }