From fc8a79255e0422fe0804109280db75e80400eb0a Mon Sep 17 00:00:00 2001 From: Ryan Tay Date: Tue, 6 Aug 2024 15:59:15 -0700 Subject: [PATCH] add time metrics Add timings Signed-off-by: Ryan Tay --- admiral/pkg/clusters/configwriter.go | 11 ++++++++++- admiral/pkg/clusters/serviceentry.go | 1 + admiral/pkg/clusters/shard_handler.go | 7 +++++++ admiral/pkg/registry/registry.go | 4 +++- 4 files changed, 21 insertions(+), 2 deletions(-) diff --git a/admiral/pkg/clusters/configwriter.go b/admiral/pkg/clusters/configwriter.go index afd24133..bf291401 100644 --- a/admiral/pkg/clusters/configwriter.go +++ b/admiral/pkg/clusters/configwriter.go @@ -5,9 +5,11 @@ import ( "sort" "strconv" "strings" + "time" "github.com/istio-ecosystem/admiral/admiral/pkg/controller/admiral" "github.com/istio-ecosystem/admiral/admiral/pkg/controller/common" + "github.com/istio-ecosystem/admiral/admiral/pkg/controller/util" "github.com/istio-ecosystem/admiral/admiral/pkg/registry" "github.com/sirupsen/logrus" networkingV1Alpha3 "istio.io/api/networking/v1alpha3" @@ -35,15 +37,20 @@ func (b *ServiceEntryBuilder) BuildServiceEntriesFromIdentityConfig(ctxLogger *l identity = identityConfig.IdentityName seMap = map[string]*networkingV1Alpha3.ServiceEntry{} serviceEntries = []*networkingV1Alpha3.ServiceEntry{} + start = time.Now() err error ) - ctxLogger.Infof(common.CtxLogFormat, "buildServiceEntry", identity, common.GetSyncNamespace(), b.ClientCluster, "Beginning to build the SE spec") + defer util.LogElapsedTime("BuildServiceEntriesFromIdentityConfig", identity, common.GetOperatorSyncNamespace(), b.ClientCluster) + ctxLogger.Infof(common.CtxLogFormat, "BuildServiceEntriesFromIdentityConfig", identity, common.GetOperatorSyncNamespace(), b.ClientCluster, "Beginning to build the SE spec") ingressEndpoints, err := getIngressEndpoints(identityConfig.Clusters) + util.LogElapsedTimeSince("getIngressEndpoints", identity, "", b.ClientCluster, start) if err != nil || len(ingressEndpoints) == 0 { return serviceEntries, err } + start = time.Now() _, isServerOnClientCluster := ingressEndpoints[b.ClientCluster] dependentNamespaces, err := getExportTo(ctxLogger, b.RemoteRegistry.RegistryClient, b.ClientCluster, isServerOnClientCluster, identityConfig.ClientAssets) + util.LogElapsedTimeSince("getExportTo", identity, "", b.ClientCluster, start) if err != nil { return serviceEntries, err } @@ -52,7 +59,9 @@ func (b *ServiceEntryBuilder) BuildServiceEntriesFromIdentityConfig(ctxLogger *l for _, identityConfigEnvironment := range identityConfigCluster.Environment { env := identityConfigEnvironment.Name var tmpSe *networkingV1Alpha3.ServiceEntry + start = time.Now() ep, err := getServiceEntryEndpoint(ctxLogger, b.ClientCluster, serverCluster, ingressEndpoints, identityConfigEnvironment) + util.LogElapsedTimeSince("getServiceEntryEndpoint", identity, env, b.ClientCluster, start) if err != nil { return serviceEntries, err } diff --git a/admiral/pkg/clusters/serviceentry.go b/admiral/pkg/clusters/serviceentry.go index ba583a5b..d239cc34 100644 --- a/admiral/pkg/clusters/serviceentry.go +++ b/admiral/pkg/clusters/serviceentry.go @@ -1074,6 +1074,7 @@ func modifySidecarForLocalClusterCommunication( if rc == nil { return fmt.Errorf("skipped modifying sidecar resource as remoteController object is nil") } + defer util.LogElapsedTime("modifySidecarForLocalClusterCommunication", sourceIdentity, sidecarNamespace, rc.ClusterID) //get existing sidecar from the cluster sidecarConfig := rc.SidecarController sidecarEgressMap.Range(func(k string, v map[string]common.SidecarEgress) { diff --git a/admiral/pkg/clusters/shard_handler.go b/admiral/pkg/clusters/shard_handler.go index aece48be..54c88afa 100644 --- a/admiral/pkg/clusters/shard_handler.go +++ b/admiral/pkg/clusters/shard_handler.go @@ -3,8 +3,10 @@ package clusters import ( "context" "fmt" + "github.com/istio-ecosystem/admiral/admiral/pkg/controller/util" "strings" "sync" + "time" admiralapiv1 "github.com/istio-ecosystem/admiral-api/pkg/apis/admiral/v1" "github.com/istio-ecosystem/admiral/admiral/pkg/registry" @@ -82,8 +84,10 @@ func HandleEventForShard(ctx context.Context, event admiral.EventType, obj *admi // of the assets on the shard, and puts those into configWriterData which go into the job channel func ProduceIdentityConfigsFromShard(ctxLogger *log.Entry, shard admiralapiv1.Shard, configWriterData chan<- *ConfigWriterData, rr *RemoteRegistry, producerWG *sync.WaitGroup) { cnames := make(map[string]string) + defer util.LogElapsedTime("ProduceIdentityConfigsFromShard", shard.Name, shard.Namespace, "") for _, clusterShard := range shard.Spec.Clusters { for _, identityItem := range clusterShard.Identities { + start := time.Now() identityConfig, err := rr.RegistryClient.GetIdentityConfigByIdentityName(identityItem.Name, ctxLogger) if err != nil { ctxLogger.Warnf(common.CtxLogFormat, "ProduceIdentityConfig", identityItem.Name, shard.Namespace, clusterShard.Name, err) @@ -125,6 +129,7 @@ func ProduceIdentityConfigsFromShard(ctxLogger *log.Entry, shard admiralapiv1.Sh ClusterName: clusterShard.Name, Error: err, } + util.LogElapsedTimeSince("ProduceIdentityConfigsFillCaches", identityItem.Name, "", clusterShard.Name, start) } } producerWG.Done() @@ -140,6 +145,7 @@ func ConsumeIdentityConfigs(ctxLogger *log.Entry, ctx context.Context, configWri assetName := identityConfig.IdentityName clientCluster := data.ClusterName ctxLogger.Infof(common.CtxLogFormat, "ConsumeIdentityConfig", assetName, "", clientCluster, "starting to consume identityConfig") + start := time.Now() serviceEntryBuilder := ServiceEntryBuilder{ClientCluster: clientCluster, RemoteRegistry: rr} serviceEntries, err := serviceEntryBuilder.BuildServiceEntriesFromIdentityConfig(ctxLogger, *identityConfig) if err != nil { @@ -201,6 +207,7 @@ func ConsumeIdentityConfigs(ctxLogger *log.Entry, ctx context.Context, configWri } } configWriterDataResults <- data + util.LogElapsedTimeSince("ConsumeIdentityConfigs", assetName, "", clientCluster, start) } } diff --git a/admiral/pkg/registry/registry.go b/admiral/pkg/registry/registry.go index a6047776..b050425e 100644 --- a/admiral/pkg/registry/registry.go +++ b/admiral/pkg/registry/registry.go @@ -3,10 +3,10 @@ package registry import ( "encoding/json" "os" - "strings" "github.com/istio-ecosystem/admiral/admiral/pkg/controller/common" + "github.com/istio-ecosystem/admiral/admiral/pkg/controller/util" log "github.com/sirupsen/logrus" ) @@ -41,6 +41,7 @@ func WithRegistryEndpoint(registryEndpoint string) func(*registryClient) { // the given identityAlias func (c *registryClient) GetIdentityConfigByIdentityName(identityAlias string, ctxLogger *log.Entry) (IdentityConfig, error) { //TODO: Use real result from registry and remove string splitting to match test file names + defer util.LogElapsedTime("GetIdentityConfigByIdentityName", identityAlias, "", "") byteValue, err := readIdentityConfigFromFile(strings.Split(identityAlias, ".")) if err != nil { ctxLogger.Infof(common.CtxLogFormat, "GetByIdentityName", identityAlias, "", "", err) @@ -64,6 +65,7 @@ func readIdentityConfigFromFile(shortAlias []string) ([]byte, error) { // GetIdentityConfigByClusterName calls the registry API to fetch the IdentityConfigs for // every identity on the cluster. func (c *registryClient) GetIdentityConfigByClusterName(clusterName string, ctxLogger *log.Entry) ([]IdentityConfig, error) { + defer util.LogElapsedTime("GetIdentityConfigByClusterName", "", "", clusterName) //TODO: need to call this function once during startup time to warm the cache //jsonResult = os.request(/cluster/{cluster_id}/configurations ctxLogger.Infof(common.CtxLogFormat, "GetByClusterName", "", "", clusterName, "")