diff --git a/cmd/controller/run.go b/cmd/controller/run.go index 7d7826925..f16955f1e 100644 --- a/cmd/controller/run.go +++ b/cmd/controller/run.go @@ -99,6 +99,9 @@ func Run(opts Options, runLog logr.Logger) error { appMetrics := metrics.NewAppMetrics() appMetrics.RegisterAllMetrics() + reconcileTimeMetrics := metrics.NewReconcileTimeMetrics() + reconcileTimeMetrics.RegisterAllMetrics() + var server *apiserver.APIServer if opts.StartAPIServer { // assign bindPort to env var KAPPCTRL_API_PORT if available @@ -198,6 +201,7 @@ func Run(opts Options, runLog logr.Logger) error { AppClient: kcClient, KcConfig: kcConfig, AppMetrics: appMetrics, + TimeMetrics: reconcileTimeMetrics, CmdRunner: sidecarCmdExec, Kubeconf: kubeconf, CompInfo: compInfo, @@ -254,6 +258,7 @@ func Run(opts Options, runLog logr.Logger) error { CoreClient: coreClient, AppClient: kcClient, KcConfig: kcConfig, + TimeMetrics: reconcileTimeMetrics, CmdRunner: sidecarCmdExec, Kubeconf: kubeconf, CacheFolder: cacheFolderPkgRepoApps, diff --git a/pkg/app/app.go b/pkg/app/app.go index 42027dcf9..678c7cca6 100644 --- a/pkg/app/app.go +++ b/pkg/app/app.go @@ -55,9 +55,10 @@ type App struct { memoizedKubernetesVersion string memoizedKubernetesAPIs []string - log logr.Logger - opts Opts - appMetrics *metrics.AppMetrics + log logr.Logger + opts Opts + appMetrics *metrics.AppMetrics + timeMetrics *metrics.ReconcileTimeMetrics pendingStatusUpdate bool flushAllStatusUpdates bool @@ -66,11 +67,11 @@ type App struct { func NewApp(app v1alpha1.App, hooks Hooks, fetchFactory fetch.Factory, templateFactory template.Factory, - deployFactory deploy.Factory, log logr.Logger, opts Opts, appMetrics *metrics.AppMetrics, compInfo ComponentInfo) *App { + deployFactory deploy.Factory, log logr.Logger, opts Opts, appMetrics *metrics.AppMetrics, timeMetrics *metrics.ReconcileTimeMetrics, compInfo ComponentInfo) *App { return &App{app: app, appPrev: *(app.DeepCopy()), hooks: hooks, fetchFactory: fetchFactory, templateFactory: templateFactory, - deployFactory: deployFactory, log: log, opts: opts, appMetrics: appMetrics, compInfo: compInfo} + deployFactory: deployFactory, log: log, opts: opts, appMetrics: appMetrics, timeMetrics: timeMetrics, compInfo: compInfo} } func (a *App) Name() string { return a.app.Name } diff --git a/pkg/app/app_deploy.go b/pkg/app/app_deploy.go index 9bc6afcc7..c9c0df564 100644 --- a/pkg/app/app_deploy.go +++ b/pkg/app/app_deploy.go @@ -5,6 +5,7 @@ package app import ( "fmt" + "time" "github.com/vmware-tanzu/carvel-kapp-controller/pkg/apis/kappctrl/v1alpha1" ctldep "github.com/vmware-tanzu/carvel-kapp-controller/pkg/deploy" @@ -13,6 +14,11 @@ import ( ) func (a *App) deploy(tplOutput string, changedFunc func(exec.CmdRunResult)) exec.CmdRunResult { + reconcileStartTS := time.Now() + defer func() { + a.timeMetrics.RegisterDeployTime(a.app.Kind, a.app.Name, a.app.Namespace, "", time.Since(reconcileStartTS)) + }() + err := a.blockDeletion() if err != nil { return exec.NewCmdRunResultWithErr(fmt.Errorf("Blocking for deploy: %s", err)) diff --git a/pkg/app/app_factory.go b/pkg/app/app_factory.go index 4b42fb86d..a37ec40b8 100644 --- a/pkg/app/app_factory.go +++ b/pkg/app/app_factory.go @@ -27,6 +27,7 @@ type CRDAppFactory struct { AppClient kcclient.Interface KcConfig *config.Config AppMetrics *metrics.AppMetrics + TimeMetrics *metrics.ReconcileTimeMetrics VendirConfigHook func(vendirconf.Config) vendirconf.Config KbldAllowBuild bool CmdRunner exec.CmdRunner @@ -48,7 +49,7 @@ func (f *CRDAppFactory) NewCRDApp(app *kcv1alpha1.App, log logr.Logger) *CRDApp templateFactory := template.NewFactory(f.CoreClient, fetchFactory, f.KbldAllowBuild, f.CmdRunner) deployFactory := deploy.NewFactory(f.CoreClient, f.Kubeconf, f.KcConfig, f.CmdRunner, log) - return NewCRDApp(app, log, f.AppMetrics, f.AppClient, fetchFactory, templateFactory, deployFactory, f.CompInfo, Opts{ + return NewCRDApp(app, log, f.AppMetrics, f.TimeMetrics, f.AppClient, fetchFactory, templateFactory, deployFactory, f.CompInfo, Opts{ DefaultSyncPeriod: f.KcConfig.AppDefaultSyncPeriod(), MinimumSyncPeriod: f.KcConfig.AppMinimumSyncPeriod(), }) diff --git a/pkg/app/app_fetch.go b/pkg/app/app_fetch.go index fd0ca8eab..67da673d3 100644 --- a/pkg/app/app_fetch.go +++ b/pkg/app/app_fetch.go @@ -20,6 +20,13 @@ const ( ) func (a *App) fetch(dstPath string) (string, exec.CmdRunResult) { + // update metrics with the total fetch time + reconcileStartTS := time.Now() + defer func() { + a.timeMetrics.RegisterFetchTime(a.app.Kind, a.app.Name, a.app.Namespace, "", time.Since(reconcileStartTS)) + }() + + // fetch init stage if len(a.app.Spec.Fetch) == 0 { return "", exec.NewCmdRunResultWithErr(fmt.Errorf("Expected at least one fetch option")) } diff --git a/pkg/app/app_reconcile.go b/pkg/app/app_reconcile.go index fc36ab365..03997bed2 100644 --- a/pkg/app/app_reconcile.go +++ b/pkg/app/app_reconcile.go @@ -103,6 +103,11 @@ func (a *App) reconcileDeploy() error { } func (a *App) reconcileFetchTemplateDeploy() exec.CmdRunResult { + reconcileStartTS := time.Now() + defer func() { + a.timeMetrics.RegisterOverallTime(a.app.Kind, a.app.Name, a.app.Namespace, "", time.Since(reconcileStartTS)) + }() + tmpDir := memdir.NewTmpDir("fetch-template-deploy") err := tmpDir.Create() diff --git a/pkg/app/app_reconcile_test.go b/pkg/app/app_reconcile_test.go index 47755dd70..25380b15b 100644 --- a/pkg/app/app_reconcile_test.go +++ b/pkg/app/app_reconcile_test.go @@ -29,7 +29,10 @@ import ( func Test_NoInspectReconcile_IfNoDeployAttempted(t *testing.T) { log := logf.Log.WithName("kc") - var appMetrics = metrics.NewAppMetrics() + var ( + appMetrics = metrics.NewAppMetrics() + timeMetrics = metrics.NewReconcileTimeMetrics() + ) // The url under fetch is invalid, which will cause this // app to fail before deploy. @@ -52,7 +55,7 @@ func Test_NoInspectReconcile_IfNoDeployAttempted(t *testing.T) { tmpFac := template.NewFactory(k8scs, fetchFac, false, exec.NewPlainCmdRunner()) deployFac := deploy.NewFactory(k8scs, kubeconfig.NewKubeconfig(k8scs, log), nil, exec.NewPlainCmdRunner(), log) - crdApp := NewCRDApp(&app, log, appMetrics, kappcs, fetchFac, tmpFac, deployFac, FakeComponentInfo{}, Opts{MinimumSyncPeriod: 30 * time.Second}) + crdApp := NewCRDApp(&app, log, appMetrics, timeMetrics, kappcs, fetchFac, tmpFac, deployFac, FakeComponentInfo{}, Opts{MinimumSyncPeriod: 30 * time.Second}) _, err := crdApp.Reconcile(false) assert.Nil(t, err, "unexpected error with reconciling", err) @@ -86,7 +89,10 @@ func Test_NoInspectReconcile_IfNoDeployAttempted(t *testing.T) { func Test_NoInspectReconcile_IfInspectNotEnabled(t *testing.T) { log := logf.Log.WithName("kc") - var appMetrics = metrics.NewAppMetrics() + var ( + appMetrics = metrics.NewAppMetrics() + timeMetrics = metrics.NewReconcileTimeMetrics() + ) app := v1alpha1.App{ ObjectMeta: metav1.ObjectMeta{ @@ -119,7 +125,7 @@ func Test_NoInspectReconcile_IfInspectNotEnabled(t *testing.T) { tmpFac := template.NewFactory(k8scs, fetchFac, false, exec.NewPlainCmdRunner()) deployFac := deploy.NewFactory(k8scs, kubeconfig.NewKubeconfig(k8scs, log), nil, exec.NewPlainCmdRunner(), log) - crdApp := NewCRDApp(&app, log, appMetrics, kappcs, fetchFac, tmpFac, deployFac, FakeComponentInfo{}, Opts{MinimumSyncPeriod: 30 * time.Second}) + crdApp := NewCRDApp(&app, log, appMetrics, timeMetrics, kappcs, fetchFac, tmpFac, deployFac, FakeComponentInfo{}, Opts{MinimumSyncPeriod: 30 * time.Second}) _, err := crdApp.Reconcile(false) assert.Nil(t, err, "unexpected error with reconciling", err) @@ -164,7 +170,10 @@ func Test_NoInspectReconcile_IfInspectNotEnabled(t *testing.T) { func Test_TemplateError_DisplayedInStatus_UsefulErrorMessageProperty(t *testing.T) { log := logf.Log.WithName("kc") - var appMetrics = metrics.NewAppMetrics() + var ( + appMetrics = metrics.NewAppMetrics() + timeMetrics = metrics.NewReconcileTimeMetrics() + ) fetchInline := map[string]string{ "file.yml": `foo: #@ data.values.nothere`, @@ -191,7 +200,7 @@ func Test_TemplateError_DisplayedInStatus_UsefulErrorMessageProperty(t *testing. tmpFac := template.NewFactory(k8scs, fetchFac, false, exec.NewPlainCmdRunner()) deployFac := deploy.NewFactory(k8scs, kubeconfig.NewKubeconfig(k8scs, log), nil, exec.NewPlainCmdRunner(), log) - crdApp := NewCRDApp(&app, log, appMetrics, kappcs, fetchFac, tmpFac, deployFac, FakeComponentInfo{}, Opts{MinimumSyncPeriod: 30 * time.Second}) + crdApp := NewCRDApp(&app, log, appMetrics, timeMetrics, kappcs, fetchFac, tmpFac, deployFac, FakeComponentInfo{}, Opts{MinimumSyncPeriod: 30 * time.Second}) _, err := crdApp.Reconcile(false) assert.Nil(t, err, "Unexpected error with reconciling", err) diff --git a/pkg/app/app_template.go b/pkg/app/app_template.go index 91b335aa5..ec8b0fd0d 100644 --- a/pkg/app/app_template.go +++ b/pkg/app/app_template.go @@ -6,6 +6,7 @@ package app import ( "fmt" "strings" + "time" "github.com/vmware-tanzu/carvel-kapp-controller/pkg/apis/kappctrl/v1alpha1" "github.com/vmware-tanzu/carvel-kapp-controller/pkg/exec" @@ -13,6 +14,11 @@ import ( ) func (a *App) template(dirPath string) exec.CmdRunResult { + reconcileStartTS := time.Now() + defer func() { + a.timeMetrics.RegisterTemplateTime(a.app.Kind, a.app.Name, a.app.Namespace, "", time.Since(reconcileStartTS)) + }() + if len(a.app.Spec.Template) == 0 { return exec.NewCmdRunResultWithErr(fmt.Errorf("Expected at least one template option")) } diff --git a/pkg/app/app_template_test.go b/pkg/app/app_template_test.go index f66d89c21..465649547 100644 --- a/pkg/app/app_template_test.go +++ b/pkg/app/app_template_test.go @@ -61,7 +61,7 @@ func Test_BuildAdditionalDownwardAPIValues_MemoizedCallCount(t *testing.T) { K8sAPIsCount: &k8sAPIsCallCount, KCVersionCount: &kcVersionCallCount, } - app := NewApp(appEmpty, Hooks{}, fetchFac, tmpFac, deployFac, log, Opts{}, metrics.NewAppMetrics(), fakeInfo) + app := NewApp(appEmpty, Hooks{}, fetchFac, tmpFac, deployFac, log, Opts{}, metrics.NewAppMetrics(), metrics.NewReconcileTimeMetrics(), fakeInfo) dir, err := os.MkdirTemp("", "temp") assert.NoError(t, err) diff --git a/pkg/app/app_test.go b/pkg/app/app_test.go index fc612db86..87e5f87b9 100644 --- a/pkg/app/app_test.go +++ b/pkg/app/app_test.go @@ -64,7 +64,7 @@ func Test_SecretRefs_RetrievesAllSecretRefs(t *testing.T) { tmpFac := template.NewFactory(k8scs, fetchFac, false, exec.NewPlainCmdRunner()) deployFac := deploy.NewFactory(k8scs, kubeconfig.NewKubeconfig(k8scs, log), nil, exec.NewPlainCmdRunner(), log) - app := apppkg.NewApp(appWithRefs, apppkg.Hooks{}, fetchFac, tmpFac, deployFac, log, apppkg.Opts{}, nil, FakeComponentInfo{}) + app := apppkg.NewApp(appWithRefs, apppkg.Hooks{}, fetchFac, tmpFac, deployFac, log, apppkg.Opts{}, nil, nil, FakeComponentInfo{}) out := app.SecretRefs() assert.Truef(t, reflect.DeepEqual(out, expected), "Expected: %s\nGot: %s\n", expected, out) @@ -88,7 +88,7 @@ func Test_SecretRefs_RetrievesNoSecretRefs_WhenNonePresent(t *testing.T) { tmpFac := template.NewFactory(k8scs, fetchFac, false, exec.NewPlainCmdRunner()) deployFac := deploy.NewFactory(k8scs, kubeconfig.NewKubeconfig(k8scs, log), nil, exec.NewPlainCmdRunner(), log) - app := apppkg.NewApp(appEmpty, apppkg.Hooks{}, fetchFac, tmpFac, deployFac, log, apppkg.Opts{}, nil, FakeComponentInfo{}) + app := apppkg.NewApp(appEmpty, apppkg.Hooks{}, fetchFac, tmpFac, deployFac, log, apppkg.Opts{}, nil, nil, FakeComponentInfo{}) out := app.SecretRefs() assert.Equal(t, 0, len(out), "No SecretRefs to be returned") @@ -126,7 +126,7 @@ func Test_ConfigMapRefs_RetrievesAllConfigMapRefs(t *testing.T) { tmpFac := template.NewFactory(k8scs, fetchFac, false, exec.NewPlainCmdRunner()) deployFac := deploy.NewFactory(k8scs, kubeconfig.NewKubeconfig(k8scs, log), nil, exec.NewPlainCmdRunner(), log) - app := apppkg.NewApp(appWithRefs, apppkg.Hooks{}, fetchFac, tmpFac, deployFac, log, apppkg.Opts{}, nil, FakeComponentInfo{}) + app := apppkg.NewApp(appWithRefs, apppkg.Hooks{}, fetchFac, tmpFac, deployFac, log, apppkg.Opts{}, nil, nil, FakeComponentInfo{}) out := app.ConfigMapRefs() assert.Truef(t, reflect.DeepEqual(out, expected), "Expected: %s\nGot: %s\n", expected, out) @@ -150,7 +150,7 @@ func Test_ConfigMapRefs_RetrievesNoConfigMapRefs_WhenNonePresent(t *testing.T) { tmpFac := template.NewFactory(k8scs, fetchFac, false, exec.NewPlainCmdRunner()) deployFac := deploy.NewFactory(k8scs, kubeconfig.NewKubeconfig(k8scs, log), nil, exec.NewPlainCmdRunner(), log) - app := apppkg.NewApp(appEmpty, apppkg.Hooks{}, fetchFac, tmpFac, deployFac, log, apppkg.Opts{}, nil, FakeComponentInfo{}) + app := apppkg.NewApp(appEmpty, apppkg.Hooks{}, fetchFac, tmpFac, deployFac, log, apppkg.Opts{}, nil, nil, FakeComponentInfo{}) out := app.ConfigMapRefs() assert.Lenf(t, out, 0, "Expected: %s\nGot: %s\n", "No ConfigMapRefs to be returned", out) diff --git a/pkg/app/crd_app.go b/pkg/app/crd_app.go index 97132754b..b5658690f 100644 --- a/pkg/app/crd_app.go +++ b/pkg/app/crd_app.go @@ -30,7 +30,7 @@ type CRDApp struct { // NewCRDApp creates new CRD app func NewCRDApp(appModel *kcv1alpha1.App, log logr.Logger, appMetrics *metrics.AppMetrics, - appClient kcclient.Interface, fetchFactory fetch.Factory, + timeMetrics *metrics.ReconcileTimeMetrics, appClient kcclient.Interface, fetchFactory fetch.Factory, templateFactory template.Factory, deployFactory deploy.Factory, compInfo ComponentInfo, opts Opts) *CRDApp { @@ -41,7 +41,7 @@ func NewCRDApp(appModel *kcv1alpha1.App, log logr.Logger, appMetrics *metrics.Ap UnblockDeletion: crdApp.unblockDeletion, UpdateStatus: crdApp.updateStatus, WatchChanges: crdApp.watchChanges, - }, fetchFactory, templateFactory, deployFactory, log, opts, appMetrics, compInfo) + }, fetchFactory, templateFactory, deployFactory, log, opts, appMetrics, timeMetrics, compInfo) return crdApp } diff --git a/pkg/metrics/reconcile_time_metrics.go b/pkg/metrics/reconcile_time_metrics.go new file mode 100644 index 000000000..7d7a10419 --- /dev/null +++ b/pkg/metrics/reconcile_time_metrics.go @@ -0,0 +1,85 @@ +package metrics + +import ( + "github.com/prometheus/client_golang/prometheus" + "sigs.k8s.io/controller-runtime/pkg/metrics" + "time" +) + +type ReconcileTimeMetrics struct { + reconcileTimeSeconds *prometheus.GaugeVec + reconcileDeployTimeSeconds *prometheus.GaugeVec + reconcileFetchTimeSeconds *prometheus.GaugeVec + reconcileTemplateTimeSeconds *prometheus.GaugeVec +} + +func NewReconcileTimeMetrics() *ReconcileTimeMetrics { + const ( + metricNamespace = "kappctrl_reconcile_time_seconds" + resourceTypeLabel = "controller" + resourceNameLabel = "name" + firstReconcileLabel = "firstReconcile" + namespace = "namespace" + ) + return &ReconcileTimeMetrics{ + reconcileTimeSeconds: prometheus.NewGaugeVec( + prometheus.GaugeOpts{ + Namespace: metricNamespace, + Name: "reconcile_time_seconds", + Help: "Overall time taken to reconcile a CR", + }, + []string{resourceTypeLabel, resourceNameLabel, namespace, firstReconcileLabel}, + ), + reconcileFetchTimeSeconds: prometheus.NewGaugeVec( + prometheus.GaugeOpts{ + Namespace: metricNamespace, + Name: "reconcile_fetch_time_seconds", + Help: "Time taken to perform a fetch for a CR", + }, + []string{resourceTypeLabel, resourceNameLabel, namespace, firstReconcileLabel}, + ), + reconcileTemplateTimeSeconds: prometheus.NewGaugeVec( + prometheus.GaugeOpts{ + Namespace: metricNamespace, + Name: "reconcile_template_time_seconds", + Help: "Time taken to perform a templating for a CR", + }, + []string{resourceTypeLabel, resourceNameLabel, namespace, firstReconcileLabel}, + ), + reconcileDeployTimeSeconds: prometheus.NewGaugeVec( + prometheus.GaugeOpts{ + Namespace: metricNamespace, + Name: "reconcile_deploy_time_seconds", + Help: "Time taken to perform a deploy for a CR", + }, + []string{resourceTypeLabel, resourceNameLabel, namespace, firstReconcileLabel}, + ), + } +} + +func (tm *ReconcileTimeMetrics) RegisterAllMetrics() { + once.Do(func() { + metrics.Registry.MustRegister( + tm.reconcileTimeSeconds, + tm.reconcileFetchTimeSeconds, + tm.reconcileTemplateTimeSeconds, + tm.reconcileDeployTimeSeconds, + ) + }) +} + +func (tm *ReconcileTimeMetrics) RegisterOverallTime(resourceType, name, namespace, firstReconcile string, time time.Duration) { + tm.reconcileTimeSeconds.WithLabelValues(resourceType, name, namespace, firstReconcile).Set(time.Seconds()) +} + +func (tm *ReconcileTimeMetrics) RegisterFetchTime(resourceType, name, namespace, firstReconcile string, time time.Duration) { + tm.reconcileFetchTimeSeconds.WithLabelValues(resourceType, name, namespace, firstReconcile).Set(time.Seconds()) +} + +func (tm *ReconcileTimeMetrics) RegisterTemplateTime(resourceType, name, namespace, firstReconcile string, time time.Duration) { + tm.reconcileTemplateTimeSeconds.WithLabelValues(resourceType, name, namespace, firstReconcile).Set(time.Seconds()) +} + +func (tm *ReconcileTimeMetrics) RegisterDeployTime(resourceType, name, namespace, firstReconcile string, time time.Duration) { + tm.reconcileDeployTimeSeconds.WithLabelValues(resourceType, name, namespace, firstReconcile).Set(time.Seconds()) +} diff --git a/pkg/pkgrepository/app.go b/pkg/pkgrepository/app.go index a6951fade..4786e5e84 100644 --- a/pkg/pkgrepository/app.go +++ b/pkg/pkgrepository/app.go @@ -8,6 +8,7 @@ import ( "github.com/vmware-tanzu/carvel-kapp-controller/pkg/apis/kappctrl/v1alpha1" "github.com/vmware-tanzu/carvel-kapp-controller/pkg/deploy" "github.com/vmware-tanzu/carvel-kapp-controller/pkg/fetch" + "github.com/vmware-tanzu/carvel-kapp-controller/pkg/metrics" "github.com/vmware-tanzu/carvel-kapp-controller/pkg/reftracker" "github.com/vmware-tanzu/carvel-kapp-controller/pkg/template" types "k8s.io/apimachinery/pkg/types" @@ -29,6 +30,8 @@ type App struct { templateFactory template.Factory deployFactory deploy.Factory + timeMetrics *metrics.ReconcileTimeMetrics + log logr.Logger pendingStatusUpdate bool @@ -36,10 +39,11 @@ type App struct { } // NewApp creates a new instance of an App based on v1alpha1.App -func NewApp(app v1alpha1.App, hooks Hooks, fetchFactory fetch.Factory, templateFactory template.Factory, deployFactory deploy.Factory, log logr.Logger, pkgRepoUID types.UID) *App { +func NewApp(app v1alpha1.App, hooks Hooks, fetchFactory fetch.Factory, templateFactory template.Factory, deployFactory deploy.Factory, + log logr.Logger, timeMetrics *metrics.ReconcileTimeMetrics, pkgRepoUID types.UID) *App { return &App{app: app, appPrev: *(app.DeepCopy()), hooks: hooks, fetchFactory: fetchFactory, templateFactory: templateFactory, - deployFactory: deployFactory, log: log, pkgRepoUID: pkgRepoUID} + deployFactory: deployFactory, log: log, timeMetrics: timeMetrics, pkgRepoUID: pkgRepoUID} } func (a *App) Name() string { return a.app.Name } diff --git a/pkg/pkgrepository/app_deploy.go b/pkg/pkgrepository/app_deploy.go index 1f5bc6131..4e2b46ebf 100644 --- a/pkg/pkgrepository/app_deploy.go +++ b/pkg/pkgrepository/app_deploy.go @@ -5,6 +5,7 @@ package pkgrepository import ( "fmt" + "time" "github.com/vmware-tanzu/carvel-kapp-controller/pkg/apis/kappctrl/v1alpha1" ctldep "github.com/vmware-tanzu/carvel-kapp-controller/pkg/deploy" @@ -13,6 +14,11 @@ import ( ) func (a *App) deploy(tplOutput string) exec.CmdRunResult { + reconcileStartTS := time.Now() + defer func() { + a.timeMetrics.RegisterDeployTime(a.app.Kind, a.app.Name, a.app.Namespace, "", time.Since(reconcileStartTS)) + }() + err := a.blockDeletion() if err != nil { return exec.NewCmdRunResultWithErr(fmt.Errorf("Blocking for deploy: %s", err)) diff --git a/pkg/pkgrepository/app_factory.go b/pkg/pkgrepository/app_factory.go index f3695baf9..faeb71b60 100644 --- a/pkg/pkgrepository/app_factory.go +++ b/pkg/pkgrepository/app_factory.go @@ -4,6 +4,7 @@ package pkgrepository import ( + "github.com/vmware-tanzu/carvel-kapp-controller/pkg/metrics" "path/filepath" "github.com/go-logr/logr" @@ -24,6 +25,7 @@ import ( type AppFactory struct { CoreClient kubernetes.Interface AppClient kcclient.Interface + TimeMetrics *metrics.ReconcileTimeMetrics KcConfig *config.Config CmdRunner exec.CmdRunner Kubeconf *kubeconfig.Kubeconfig @@ -39,5 +41,5 @@ func (f *AppFactory) NewCRDPackageRepo(app *kcv1alpha1.App, pkgr *pkgv1alpha1.Pa fetchFactory := fetch.NewFactory(f.CoreClient, vendirOpts, f.CmdRunner) templateFactory := template.NewFactory(f.CoreClient, fetchFactory, false, f.CmdRunner) deployFactory := deploy.NewFactory(f.CoreClient, f.Kubeconf, nil, f.CmdRunner, log) - return NewCRDApp(app, pkgr, log, f.AppClient, fetchFactory, templateFactory, deployFactory) + return NewCRDApp(app, pkgr, log, f.AppClient, f.TimeMetrics, fetchFactory, templateFactory, deployFactory) } diff --git a/pkg/pkgrepository/app_fetch.go b/pkg/pkgrepository/app_fetch.go index 86839d787..495f3b1b5 100644 --- a/pkg/pkgrepository/app_fetch.go +++ b/pkg/pkgrepository/app_fetch.go @@ -14,6 +14,10 @@ import ( ) func (a *App) fetch(dstPath string) (string, exec.CmdRunResult) { + reconcileStartTS := time.Now() + defer func() { + a.timeMetrics.RegisterFetchTime(a.app.Kind, a.app.Name, a.app.Namespace, "", time.Since(reconcileStartTS)) + }() if len(a.app.Spec.Fetch) == 0 { return "", exec.NewCmdRunResultWithErr(fmt.Errorf("Expected at least one fetch option")) } diff --git a/pkg/pkgrepository/app_reconcile.go b/pkg/pkgrepository/app_reconcile.go index 288f45d05..bee2bb034 100644 --- a/pkg/pkgrepository/app_reconcile.go +++ b/pkg/pkgrepository/app_reconcile.go @@ -90,6 +90,11 @@ func (a *App) reconcileDeploy() error { } func (a *App) reconcileFetchTemplateDeploy() exec.CmdRunResult { + reconcileStartTS := time.Now() + defer func() { + a.timeMetrics.RegisterOverallTime(a.app.Kind, a.app.Name, a.app.Namespace, "", time.Since(reconcileStartTS)) + }() + tmpDir := memdir.NewTmpDir("fetch-template-deploy") err := tmpDir.Create() diff --git a/pkg/pkgrepository/app_reconcile_test.go b/pkg/pkgrepository/app_reconcile_test.go index 9962d1820..e9268c8b1 100644 --- a/pkg/pkgrepository/app_reconcile_test.go +++ b/pkg/pkgrepository/app_reconcile_test.go @@ -4,6 +4,7 @@ package pkgrepository import ( + "github.com/vmware-tanzu/carvel-kapp-controller/pkg/metrics" "testing" "github.com/stretchr/testify/assert" @@ -24,6 +25,7 @@ import ( func Test_NoInspectReconcile_IfNoDeployAttempted(t *testing.T) { log := logf.Log.WithName("kc") + var timeMetrics = metrics.NewReconcileTimeMetrics() // The url under fetch is invalid, which will cause this // app to fail before deploy. @@ -46,7 +48,7 @@ func Test_NoInspectReconcile_IfNoDeployAttempted(t *testing.T) { deployFac := deploy.NewFactory(k8scs, kubeconfig.NewKubeconfig(k8scs, log), nil, exec.NewPlainCmdRunner(), log) pkgr := v1alpha12.PackageRepository{} - crdApp := NewCRDApp(&app, &pkgr, log, kappcs, fetchFac, tmpFac, deployFac) + crdApp := NewCRDApp(&app, &pkgr, log, kappcs, timeMetrics, fetchFac, tmpFac, deployFac) _, err := crdApp.Reconcile(false) if err != nil { t.Fatalf("Unexpected error with reconciling: %v", err) @@ -78,6 +80,7 @@ func Test_NoInspectReconcile_IfNoDeployAttempted(t *testing.T) { func Test_TemplateError_DisplayedInStatus_UsefulErrorMessageProperty(t *testing.T) { log := logf.Log.WithName("kc") + var timeMetrics = metrics.NewReconcileTimeMetrics() fetchInline := map[string]string{ "packages/file.yml": `foo: #@ data.values.nothere`, @@ -102,7 +105,7 @@ func Test_TemplateError_DisplayedInStatus_UsefulErrorMessageProperty(t *testing. deployFac := deploy.NewFactory(k8scs, kubeconfig.NewKubeconfig(k8scs, log), nil, exec.NewPlainCmdRunner(), log) pkgr := v1alpha12.PackageRepository{} - crdApp := NewCRDApp(&app, &pkgr, log, kappcs, fetchFac, tmpFac, deployFac) + crdApp := NewCRDApp(&app, &pkgr, log, kappcs, timeMetrics, fetchFac, tmpFac, deployFac) _, err := crdApp.Reconcile(false) if err != nil { t.Fatalf("Unexpected error with reconciling: %v", err) @@ -135,6 +138,7 @@ func Test_TemplateError_DisplayedInStatus_UsefulErrorMessageProperty(t *testing. func TestInvalidPackageRepositoryFormat(t *testing.T) { log := logf.Log.WithName("kc") + var timeMetrics = metrics.NewReconcileTimeMetrics() fetchInline := map[string]string{ "file.yml": `foo: hi`, @@ -158,7 +162,7 @@ func TestInvalidPackageRepositoryFormat(t *testing.T) { deployFac := deploy.NewFactory(k8scs, kubeconfig.NewKubeconfig(k8scs, log), nil, exec.NewPlainCmdRunner(), log) pkgr := v1alpha12.PackageRepository{} - crdApp := NewCRDApp(&app, &pkgr, log, kappcs, fetchFac, tmpFac, deployFac) + crdApp := NewCRDApp(&app, &pkgr, log, kappcs, timeMetrics, fetchFac, tmpFac, deployFac) _, err := crdApp.Reconcile(false) if err != nil { t.Fatalf("Unexpected error with reconciling: %v", err) diff --git a/pkg/pkgrepository/app_template.go b/pkg/pkgrepository/app_template.go index 241cee7ee..f98761764 100644 --- a/pkg/pkgrepository/app_template.go +++ b/pkg/pkgrepository/app_template.go @@ -11,6 +11,7 @@ import ( "os" "path/filepath" "strings" + "time" kcv1alpha1 "github.com/vmware-tanzu/carvel-kapp-controller/pkg/apis/kappctrl/v1alpha1" datapackagingv1alpha1 "github.com/vmware-tanzu/carvel-kapp-controller/pkg/apiserver/apis/datapackaging/v1alpha1" @@ -25,6 +26,11 @@ import ( var errInvalidPackageRepo = exec.NewCmdRunResultWithErr(fmt.Errorf("Invalid package repository content: must contain 'packages/' directory but did not")) func (a *App) template(dirPath string) exec.CmdRunResult { + reconcileStartTS := time.Now() + defer func() { + a.timeMetrics.RegisterTemplateTime(a.app.Kind, a.app.Name, a.app.Namespace, "", time.Since(reconcileStartTS)) + }() + fileInfo, err := os.Lstat(filepath.Join(dirPath, "packages")) if err != nil { if os.IsNotExist(err) { diff --git a/pkg/pkgrepository/crd_app.go b/pkg/pkgrepository/crd_app.go index c6bdbabc8..5f02ae5d7 100644 --- a/pkg/pkgrepository/crd_app.go +++ b/pkg/pkgrepository/crd_app.go @@ -6,6 +6,7 @@ package pkgrepository import ( "context" "fmt" + "github.com/vmware-tanzu/carvel-kapp-controller/pkg/metrics" "github.com/go-logr/logr" kcv1alpha1 "github.com/vmware-tanzu/carvel-kapp-controller/pkg/apis/kappctrl/v1alpha1" @@ -20,15 +21,16 @@ import ( ) type CRDApp struct { - app *App - appModel *kcv1alpha1.App - pkgrModel *pkgingv1alpha1.PackageRepository - log logr.Logger - appClient kcclient.Interface + app *App + appModel *kcv1alpha1.App + pkgrModel *pkgingv1alpha1.PackageRepository + timeMetrics *metrics.ReconcileTimeMetrics + log logr.Logger + appClient kcclient.Interface } func NewCRDApp(appModel *kcv1alpha1.App, packageRepo *pkgingv1alpha1.PackageRepository, log logr.Logger, - appClient kcclient.Interface, fetchFactory fetch.Factory, + appClient kcclient.Interface, timeMetrics *metrics.ReconcileTimeMetrics, fetchFactory fetch.Factory, templateFactory template.Factory, deployFactory deploy.Factory) *CRDApp { crdApp := &CRDApp{appModel: appModel, pkgrModel: packageRepo, log: log, appClient: appClient} @@ -37,7 +39,7 @@ func NewCRDApp(appModel *kcv1alpha1.App, packageRepo *pkgingv1alpha1.PackageRepo BlockDeletion: crdApp.blockDeletion, UnblockDeletion: crdApp.unblockDeletion, UpdateStatus: crdApp.updateStatus, - }, fetchFactory, templateFactory, deployFactory, log, packageRepo.UID) + }, fetchFactory, templateFactory, deployFactory, log, timeMetrics, packageRepo.UID) return crdApp }