From 8e3942d69cd44443aa72e50e8643fdd85a7fa63e Mon Sep 17 00:00:00 2001 From: jacksontong Date: Fri, 26 Jul 2024 23:06:47 +0800 Subject: [PATCH] record time of app processing procedure --- .../controller/app/action/install.go | 26 ++++++++++++++++++- .../controller/app/action/uninstall.go | 22 ++++++++++++++++ .../controller/app/action/upgrade.go | 25 ++++++++++++++++++ pkg/application/helm/action/install.go | 6 ++--- pkg/application/helm/action/upgrade.go | 12 ++++----- 5 files changed, 81 insertions(+), 10 deletions(-) diff --git a/pkg/application/controller/app/action/install.go b/pkg/application/controller/app/action/install.go index ca25902f4..f7f4d5949 100644 --- a/pkg/application/controller/app/action/install.go +++ b/pkg/application/controller/app/action/install.go @@ -22,6 +22,7 @@ import ( "context" "errors" "fmt" + "time" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" applicationv1 "tkestack.io/tke/api/application/v1" @@ -46,7 +47,28 @@ func Install(ctx context.Context, updateStatusFunc applicationprovider.UpdateStatusFunc) (*applicationv1.App, error) { hooks := getHooks(app) + var beginInstallTime, preInstallTime, pullChartTime, installTime, postInstallTime time.Time + defer func() { + var preInstallCost, pullChartCost, installCost, postInstallCost int + if !preInstallTime.IsZero() { + preInstallCost = int(preInstallTime.Sub(beginInstallTime).Seconds()) + if !pullChartTime.IsZero() { + pullChartCost = int(pullChartTime.Sub(preInstallTime).Seconds()) + if !installTime.IsZero() { + installCost = int(installTime.Sub(pullChartTime).Seconds()) + if !postInstallTime.IsZero() { + postInstallCost = int(postInstallTime.Sub(installTime).Milliseconds()) + } + } + } + } + log.Infof("handle for %s/%s cost: %d %d %d %d", + app.Namespace, app.Name, preInstallCost, pullChartCost, installCost, postInstallCost) + }() + + beginInstallTime = time.Now() err := hooks.PreInstall(ctx, applicationClient, platformClient, app, repo, updateStatusFunc) + preInstallTime = time.Now() if err != nil { if updateStatusFunc != nil { newStatus := app.Status.DeepCopy() @@ -65,6 +87,7 @@ func Install(ctx context.Context, } destfile, err := Pull(ctx, applicationClient, platformClient, app, repo, updateStatusFunc) + pullChartTime = time.Now() if err != nil { newStatus := app.Status.DeepCopy() if updateStatusFunc != nil { @@ -131,7 +154,7 @@ func Install(ctx context.Context, Wait: app.Spec.Chart.InstallPara.Wait, WaitForJobs: app.Spec.Chart.InstallPara.WaitForJobs, }) - + installTime = time.Now() if err != nil { if errors.Is(err, errors.New("chart manifest is empty")) { log.Errorf(fmt.Sprintf("ERROR: install cluster %s app %s manifest is empty, file %s", app.Spec.TargetCluster, app.Name, destfile)) @@ -158,6 +181,7 @@ func Install(ctx context.Context, } err = hooks.PostInstall(ctx, applicationClient, platformClient, app, repo, updateStatusFunc) + postInstallTime = time.Now() // 先走完hook，在更新app状态为succeed if err != nil { if updateStatusFunc != nil { diff --git a/pkg/application/controller/app/action/uninstall.go b/pkg/application/controller/app/action/uninstall.go index b63d808d2..be07539fc 100644 --- a/pkg/application/controller/app/action/uninstall.go +++ b/pkg/application/controller/app/action/uninstall.go @@ -21,6 +21,7 @@ package action import ( "context" "errors" + "time" "helm.sh/helm/v3/pkg/release" "helm.sh/helm/v3/pkg/storage/driver" @@ -30,6 +31,7 @@ import ( appconfig "tkestack.io/tke/pkg/application/config" helmaction "tkestack.io/tke/pkg/application/helm/action" "tkestack.io/tke/pkg/application/util" + "tkestack.io/tke/pkg/util/log" ) // Uninstall provides the implementation of 'helm uninstall'. @@ -39,7 +41,25 @@ func Uninstall(ctx context.Context, app *applicationv1.App, repo appconfig.RepoConfiguration) (*release.UninstallReleaseResponse, error) { hooks := getHooks(app) + + var beginUninstallTime, preUninstallTime, uninstallTime, postUninstallTime time.Time + defer func() { + var preUninstallCost, uninstallCost, postUninstallCost int + if !preUninstallTime.IsZero() { + preUninstallCost = int(preUninstallTime.Sub(beginUninstallTime).Seconds()) + if !uninstallTime.IsZero() { + uninstallCost = int(uninstallTime.Sub(preUninstallTime).Seconds()) + if !postUninstallTime.IsZero() { + postUninstallCost = int(postUninstallTime.Sub(uninstallTime).Seconds()) + } + } + } + log.Infof("handle for %s/%s cost: %d %d %d", + app.Namespace, app.Name, preUninstallCost, uninstallCost, postUninstallCost) + }() + beginUninstallTime = time.Now() err := hooks.PreUninstall(ctx, applicationClient, platformClient, app, repo) + preUninstallTime = time.Now() if err != nil { return nil, err } @@ -52,11 +72,13 @@ func Uninstall(ctx context.Context, ReleaseName: app.Spec.Name, Timeout: defaultTimeout, }) + uninstallTime = time.Now() if err != nil && !errors.Is(err, driver.ErrReleaseNotFound) { return resp, err } err = hooks.PostUninstall(ctx, applicationClient, platformClient, app, repo) + postUninstallTime = time.Now() return resp, err } diff --git a/pkg/application/controller/app/action/upgrade.go b/pkg/application/controller/app/action/upgrade.go index e3772c813..f72eb31d4 100644 --- a/pkg/application/controller/app/action/upgrade.go +++ b/pkg/application/controller/app/action/upgrade.go @@ -22,6 +22,7 @@ import ( "context" "errors" "fmt" + "time" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" applicationv1 "tkestack.io/tke/api/application/v1" @@ -46,7 +47,28 @@ func Upgrade(ctx context.Context, updateStatusFunc applicationprovider.UpdateStatusFunc) (*applicationv1.App, error) { hooks := getHooks(app) + var beginUpgradeTime, preUpgradeTime, pullChartTime, upgradeTime, postupgradeTime time.Time + defer func() { + var preUpgradeCost, pullChartCost, upgradeCost, postUpgradeCost int + if !preUpgradeTime.IsZero() { + preUpgradeCost = int(preUpgradeTime.Sub(beginUpgradeTime).Seconds()) + if !pullChartTime.IsZero() { + pullChartCost = int(pullChartTime.Sub(preUpgradeTime).Seconds()) + if !upgradeTime.IsZero() { + upgradeCost = int(upgradeTime.Sub(pullChartTime).Seconds()) + if !postupgradeTime.IsZero() { + postUpgradeCost = int(postupgradeTime.Sub(upgradeTime).Milliseconds()) + } + } + } + } + log.Infof("handle for %s/%s cost: %d %d %d %d", + app.Namespace, app.Name, preUpgradeCost, pullChartCost, upgradeCost, postUpgradeCost) + }() + + beginUpgradeTime = time.Now() err := hooks.PreUpgrade(ctx, applicationClient, platformClient, app, repo, updateStatusFunc) + preUpgradeTime = time.Now() if err != nil { if updateStatusFunc != nil { newStatus := app.Status.DeepCopy() @@ -65,6 +87,7 @@ func Upgrade(ctx context.Context, } destfile, err := Pull(ctx, applicationClient, platformClient, app, repo, updateStatusFunc) + pullChartTime = time.Now() if err != nil { newStatus := app.Status.DeepCopy() if updateStatusFunc != nil { @@ -124,6 +147,7 @@ func Upgrade(ctx context.Context, Wait: app.Spec.Chart.UpgradePara.Wait, WaitForJobs: app.Spec.Chart.UpgradePara.WaitForJobs, }) + upgradeTime = time.Now() if err != nil { if errors.Is(err, errors.New("chart manifest is empty")) { log.Errorf(fmt.Sprintf("ERROR: upgrade cluster %s app %s manifest is empty, file %s", app.Spec.TargetCluster, app.Name, destfile)) @@ -191,6 +215,7 @@ func Upgrade(ctx context.Context, } err = hooks.PostUpgrade(ctx, applicationClient, platformClient, app, repo, updateStatusFunc) + postupgradeTime = time.Now() // 先走完hook，在更新app状态为succeed if err != nil { if updateStatusFunc != nil { diff --git a/pkg/application/helm/action/install.go b/pkg/application/helm/action/install.go index 440fd0098..1a9150040 100644 --- a/pkg/application/helm/action/install.go +++ b/pkg/application/helm/action/install.go @@ -111,11 +111,11 @@ func (c *Client) InstallWithLocal(ctx context.Context, options *InstallOptions, for _, rel := range rels { if rel.Info.Status == release.StatusDeployed { // release 记录已存在，状态为deployed，不再进行重复安装 - log.Infof("Release %s is already exist. igonre it now.", options.ReleaseName) + log.Infof("Release %s for %s is already exist. igonre it now.", options.ReleaseName, options.Namespace) return nil, nil } // release 记录已存在，状态为其他，删除重试 - log.Infof("install release %s is already exist, status is %s. delete it now.", options.ReleaseName, rel.Info.Status) + log.Infof("install release %s for %s is already exist, status is %s. delete it now.", options.ReleaseName, options.Namespace, rel.Info.Status) actionConfig.Releases.Delete(rel.Name, rel.Version) } } @@ -184,7 +184,7 @@ func (c *Client) InstallWithLocal(ctx context.Context, options *InstallOptions, } if chartRequested.Metadata.Deprecated { - log.Warnf("This chart %s/%s is deprecated", options.ChartRepo, options.Chart) + log.Warnf("This chart %s/%s for %s is deprecated", options.ChartRepo, options.Chart, options.Namespace) } if req := chartRequested.Metadata.Dependencies; req != nil { diff --git a/pkg/application/helm/action/upgrade.go b/pkg/application/helm/action/upgrade.go index eb4dc73b3..05cd39f42 100644 --- a/pkg/application/helm/action/upgrade.go +++ b/pkg/application/helm/action/upgrade.go @@ -80,7 +80,7 @@ func (c *Client) Upgrade(ctx context.Context, options *UpgradeOptions) (*release histClient.Max = 1 rels, err := histClient.Run(options.ReleaseName) if errors.Is(err, driver.ErrReleaseNotFound) { - log.Infof("Release %d does not exist. Installing it now.", options.ReleaseName) + log.Infof("Release %d for %s does not exist. Installing it now.", options.ReleaseName, options.Namespace) return c.Install(ctx, &InstallOptions{ DryRun: options.DryRun, DependencyUpdate: options.DependencyUpdate, @@ -100,7 +100,7 @@ func (c *Client) Upgrade(ctx context.Context, options *UpgradeOptions) (*release for _, rel := range rels { if rel.Info.Status == release.StatusPendingInstall || rel.Info.Status == release.StatusPendingUpgrade || rel.Info.Status == release.StatusPendingRollback { // if release is pending, delete it. - log.Infof("upgrade release %s is already exist, status is %s. delete it now.", options.ReleaseName, rel.Info.Status) + log.Infof("upgrade release %s for %s is already exist, status is %s. delete it now.", options.ReleaseName, options.Namespace, rel.Info.Status) actionConfig.Releases.Delete(rel.Name, rel.Version) } } @@ -171,19 +171,19 @@ func (c *Client) Upgrade(ctx context.Context, options *UpgradeOptions) (*release } if chartRequested.Metadata.Deprecated { - log.Warnf("This chart %s/%s is deprecated", options.ChartRepo, options.Chart) + log.Warnf("This chart %s/%s for %s is deprecated", options.ChartRepo, options.Chart, options.Namespace) } rel, err := client.RunWithContext(ctx, options.ReleaseName, chartRequested, options.Values) // if current release resource is deprecated, delete it. if err != nil { - log.Infof("upgrade %s RunWithContext failed,err:%s.", options.ReleaseName, err.Error()) + log.Infof("upgrade %s for %s RunWithContext failed,err:%s.", options.ReleaseName, options.Namespace, err.Error()) } if err != nil && strings.Contains(err.Error(), "unable to build kubernetes objects from current release manifest") { histClient := action.NewHistory(actionConfig) histClient.Max = 1 rels, err := histClient.Run(options.ReleaseName) if err != nil { - log.Infof("upgrade get release %s history failed. err:%s.", options.ReleaseName, err.Error()) + log.Infof("upgrade get release %s history for %s failed. err:%s.", options.ReleaseName, options.Namespace, err.Error()) return nil, err } if len(rels) == 0 { @@ -191,7 +191,7 @@ func (c *Client) Upgrade(ctx context.Context, options *UpgradeOptions) (*release } for _, rel := range rels { // if release is deprecated, delete it. - log.Infof("upgrade release %s resource is deprecated. delete it now. rel name:%s, rel version:%d.", options.ReleaseName, rel.Name, rel.Version) + log.Infof("upgrade release %s resource for %s is deprecated. delete it now. rel name:%s, rel version:%d.", options.ReleaseName, options.Namespace, rel.Name, rel.Version) actionConfig.Releases.Delete(rel.Name, rel.Version) } }