From f053e55057d7d2eba0bc40b2b92e9a7163d6c811 Mon Sep 17 00:00:00 2001 From: Lency Qian <36918585+LeiQL@users.noreply.github.com> Date: Thu, 19 Sep 2024 13:19:28 +0800 Subject: [PATCH] Log improvement for Targets (#452) * target logs * fix iot test * logging * Add trace value in unwinding parent catalogs (#454) * add traceValue when read catalog property in parent catalog * update trace value * Turn off validation in standalone mode for cross type check (#446) * Turn off standalone validation for cross type check * Handle state.Spec is nil --------- Co-authored-by: Jiawei Du <59427055+msftcoderdjw@users.noreply.github.com> * add parent circular dependency check in catalog validation (#453) * add parent circular dependency validation * update manifest name * update helper function --------- Co-authored-by: Jiawei Du <59427055+msftcoderdjw@users.noreply.github.com> * Block campaign update and delete with running activation (#458) * update actions/upload-artifact version from v2 to v4 (#461) * Support parsing nested JSON properties and schema check for nested properties (#398) * support nested json properties * update go mod for coa * update scenario 04 * update go.sum * go mod tidy * update ut and syntax * update schema doc * fix test case * update samples * add doc for gojq * revert file Signed-off-by: linyguo * revert file Signed-off-by: linyguo * revert symphony-ghcr-values.yaml * merge update unit test * resolve go mod * update gojq format string * revert sample changes * update * update config expression check and docs --------- Signed-off-by: linyguo Co-authored-by: Jiawei Du <59427055+msftcoderdjw@users.noreply.github.com> * update canary sample for minikube (#462) * Log lines improvement for workflow and solution deployment and small refactors (#447) * Log lines improvement and small refactors * return status when nextStage is not empty * Check pause status when selfDriving is false. Fix typo * Check pauseRequested regardless of selfDriving or not --------- Co-authored-by: Jiawei Du <59427055+msftcoderdjw@users.noreply.github.com> * fixed broken markdown links (#471) * use () to convert expression output to string (#470) * add context in evaluation context (#459) * add context in evaluation context * update context in stage manager --------- Co-authored-by: Jiawei Du <59427055+msftcoderdjw@users.noreply.github.com> * checking if the activation still exist for waitcount = 0 or waitcount very large. (#460) Co-authored-by: Jiawei Du <59427055+msftcoderdjw@users.noreply.github.com> * fix helm test --------- Signed-off-by: linyguo Co-authored-by: Jiawei Du <59427055+msftcoderdjw@users.noreply.github.com> Co-authored-by: linyguo Co-authored-by: Xingdong Li Co-authored-by: Renjie Li Co-authored-by: Haishi2016 --- .../apis/v1alpha1/providers/target/adb/adb.go | 22 +++-- .../providers/target/azure/adu/adu.go | 5 +- .../providers/target/azure/iotedge/iotedge.go | 46 +++++---- .../target/azure/iotedge/iotedge_test.go | 40 ++++---- .../providers/target/configmap/configmap.go | 11 ++- .../providers/target/docker/docker.go | 13 +++ .../v1alpha1/providers/target/helm/helm.go | 19 +++- .../providers/target/helm/helm_test.go | 4 +- .../v1alpha1/providers/target/http/http.go | 11 ++- .../providers/target/ingress/ingress.go | 13 ++- .../apis/v1alpha1/providers/target/k8s/k8s.go | 98 ++++++++++--------- .../providers/target/kubectl/kubectl.go | 11 ++- .../v1alpha1/providers/target/mqtt/mqtt.go | 12 ++- .../v1alpha1/providers/target/proxy/proxy.go | 6 ++ .../providers/target/script/script.go | 4 + .../providers/target/staging/staging.go | 11 ++- .../target/win10/sideload/sideload.go | 8 +- 17 files changed, 212 insertions(+), 122 deletions(-) diff --git a/api/pkg/apis/v1alpha1/providers/target/adb/adb.go b/api/pkg/apis/v1alpha1/providers/target/adb/adb.go index 79c4d7230..436d79556 100644 --- a/api/pkg/apis/v1alpha1/providers/target/adb/adb.go +++ b/api/pkg/apis/v1alpha1/providers/target/adb/adb.go @@ -47,6 +47,7 @@ func AdbProviderConfigFromMap(properties map[string]string) (AdbProviderConfig, func (i *AdbProvider) InitWithMap(properties map[string]string) error { config, err := AdbProviderConfigFromMap(properties) if err != nil { + aLog.Errorf(" P (Android ADB Target): expected AdbProviderConfig: %+v", err) return err } return i.Init(config) @@ -63,11 +64,11 @@ func (i *AdbProvider) Init(config providers.IProviderConfig) error { defer observ_utils.CloseSpanWithError(span, &err) defer observ_utils.EmitUserDiagnosticsLogs(ctx, &err) - aLog.InfoCtx(ctx, " P (Android ADB): Init()") + aLog.InfoCtx(ctx, " P (Android ADB Target): Init()") updateConfig, err := toAdbProviderConfig(config) if err != nil { - aLog.Errorf(" P (Android ADB): expected AdbProviderConfig: %+v", err) + aLog.ErrorfCtx(ctx, " P (Android ADB Target): expected AdbProviderConfig: %+v", err) return errors.New("expected AdbProviderConfig") } i.Config = updateConfig @@ -94,10 +95,10 @@ func (i *AdbProvider) Get(ctx context.Context, deployment model.DeploymentSpec, if deployment.Instance.Spec == nil { err = errors.New("deployment instance spec is nil") - aLog.ErrorfCtx(ctx, " P (Android ADB): failed to get deployment, error: %+v", err) + aLog.ErrorfCtx(ctx, " P (Android ADB Target): failed to get deployment, error: %+v", err) return nil, err } - aLog.InfofCtx(ctx, " P (Android ADB): getting artifacts: %s - %s", deployment.Instance.Spec.Scope, deployment.Instance.ObjectMeta.Name) + aLog.InfofCtx(ctx, " P (Android ADB Target): getting artifacts: %s - %s", deployment.Instance.Spec.Scope, deployment.Instance.ObjectMeta.Name) ret := make([]model.ComponentSpec, 0) @@ -115,7 +116,7 @@ func (i *AdbProvider) Get(ctx context.Context, deployment model.DeploymentSpec, out, err = exec.Command("adb", params...).Output() if err != nil { - aLog.ErrorfCtx(ctx, " P (Android ADB): failed to get application %+v, error: %+v", p, err) + aLog.ErrorfCtx(ctx, " P (Android ADB Target): failed to get application %+v, error: %+v", p, err) return nil, err } str := string(out) @@ -141,22 +142,24 @@ func (i *AdbProvider) Apply(ctx context.Context, deployment model.DeploymentSpec defer observ_utils.CloseSpanWithError(span, &err) defer observ_utils.EmitUserDiagnosticsLogs(ctx, &err) - aLog.InfofCtx(ctx, " P (Android ADB Provider): applying artifacts: %s - %s", deployment.Instance.Spec.Scope, deployment.Instance.ObjectMeta.Name) + aLog.InfofCtx(ctx, " P (Android ADB Target): applying artifacts: %s - %s", deployment.Instance.Spec.Scope, deployment.Instance.ObjectMeta.Name) components := step.GetComponents() err = i.GetValidationRule(ctx).Validate(components) if err != nil { - aLog.ErrorfCtx(ctx, " P (Android ADB Provider): failed to validate components, error: %v", err) + aLog.ErrorfCtx(ctx, " P (Android ADB Target): failed to validate components, error: %v", err) return nil, err } if isDryRun { + aLog.DebugCtx(ctx, " P (Android ADB Target): dryRun is enabled, skipping apply") err = nil return nil, nil } ret := step.PrepareResultMap() components = step.GetUpdatedComponents() if len(components) > 0 { + aLog.InfofCtx(ctx, " P (Android ADB Target): get updated components: count - %d", len(components)) for _, component := range components { if component.Name != "" { if p, ok := component.Properties[model.AppImage]; ok && p != "" { @@ -167,7 +170,7 @@ func (i *AdbProvider) Apply(ctx context.Context, deployment model.DeploymentSpec cmd := exec.Command("adb", params...) err = cmd.Run() if err != nil { - aLog.ErrorfCtx(ctx, " P (Android ADB): failed to install application %+v, error: %+v", p, err) + aLog.ErrorfCtx(ctx, " P (Android ADB Target): failed to install application %+v, error: %+v", p, err) ret[component.Name] = model.ComponentResultSpec{ Status: v1alpha2.UpdateFailed, Message: err.Error(), @@ -181,6 +184,7 @@ func (i *AdbProvider) Apply(ctx context.Context, deployment model.DeploymentSpec } components = step.GetDeletedComponents() if len(components) > 0 { + aLog.InfofCtx(ctx, " P (Android ADB Target): get deleted components: count - %d", len(components)) for _, component := range components { if component.Name != "" { if p, ok := component.Properties[model.AppPackage]; ok && p != "" { @@ -191,7 +195,7 @@ func (i *AdbProvider) Apply(ctx context.Context, deployment model.DeploymentSpec cmd := exec.Command("adb", params...) err = cmd.Run() if err != nil { - aLog.ErrorfCtx(ctx, " P (Android ADB): failed to uninstall application %+v, error: %+v", p, err) + aLog.ErrorfCtx(ctx, " P (Android ADB Target): failed to uninstall application %+v, error: %+v", p, err) ret[component.Name] = model.ComponentResultSpec{ Status: v1alpha2.DeleteFailed, Message: err.Error(), diff --git a/api/pkg/apis/v1alpha1/providers/target/azure/adu/adu.go b/api/pkg/apis/v1alpha1/providers/target/azure/adu/adu.go index 6a68f3c94..4363e3ada 100644 --- a/api/pkg/apis/v1alpha1/providers/target/azure/adu/adu.go +++ b/api/pkg/apis/v1alpha1/providers/target/azure/adu/adu.go @@ -81,7 +81,7 @@ func ADUTargetProviderConfigFromMap(properties map[string]string) (ADUTargetProv func (i *ADUTargetProvider) InitWithMap(properties map[string]string) error { config, err := ADUTargetProviderConfigFromMap(properties) if err != nil { - sLog.Errorf(" P (ADU Target): expected ADUTargetProviderConfig %+v", err) + sLog.Errorf(" P (ADU Target): expected ADUTargetProviderConfig: %+v", err) return err } return i.Init(config) @@ -103,7 +103,7 @@ func (i *ADUTargetProvider) Init(config providers.IProviderConfig) error { updateConfig, err := toADUTargetProviderConfig(config) if err != nil { - sLog.Errorf(" P (ADU Target): expected ADUTargetProviderConfig: %+v", err) + sLog.ErrorfCtx(ctx, " P (ADU Target): expected ADUTargetProviderConfig: %+v", err) return err } i.Config = updateConfig @@ -205,6 +205,7 @@ func (i *ADUTargetProvider) Apply(ctx context.Context, deployment model.Deployme return nil, err } if isDryRun { + sLog.DebugCtx(ctx, " P (ADU Target): dryRun is enabled, skipping apply") err = nil return nil, nil } diff --git a/api/pkg/apis/v1alpha1/providers/target/azure/iotedge/iotedge.go b/api/pkg/apis/v1alpha1/providers/target/azure/iotedge/iotedge.go index c89781346..374f96dad 100644 --- a/api/pkg/apis/v1alpha1/providers/target/azure/iotedge/iotedge.go +++ b/api/pkg/apis/v1alpha1/providers/target/azure/iotedge/iotedge.go @@ -151,6 +151,7 @@ func IoTEdgeTargetProviderConfigFromMap(properties map[string]string) (IoTEdgeTa func (i *IoTEdgeTargetProvider) InitWithMap(properties map[string]string) error { config, err := IoTEdgeTargetProviderConfigFromMap(properties) if err != nil { + sLog.Errorf(" P (IoT Edge Target): expected IoTEdgeTargetProviderConfig: %+v", err) return err } return i.Init(config) @@ -235,9 +236,11 @@ func (i *IoTEdgeTargetProvider) Apply(ctx context.Context, deployment model.Depl components := step.GetComponents() err = i.GetValidationRule(ctx).Validate(components) if err != nil { + sLog.ErrorfCtx(ctx, " P (IoT Edge Target): failed to validate components: %+v", err) return nil, err } if isDryRun { + sLog.DebugfCtx(ctx, " P (IoT Edge Target): dry run, no action taken") err = nil return nil, nil } @@ -272,6 +275,7 @@ func (i *IoTEdgeTargetProvider) Apply(ctx context.Context, deployment model.Depl modules[a.Name] = module } if len(modules) > 0 { + sLog.InfofCtx(ctx, " P (IoT Edge Target): deploy to IoT edge with modules count %d", len(modules)) err = i.deployToIoTEdge(ctx, deployment.Instance.ObjectMeta.Name, deployment.Instance.Spec.Metadata, modules, edgeAgent, edgeHub) if err != nil { sLog.ErrorfCtx(ctx, " P (IoT Edge Target): failed to deploy to IoT edge: %+v", err) @@ -294,6 +298,7 @@ func (i *IoTEdgeTargetProvider) Apply(ctx context.Context, deployment model.Depl modules[a.Name] = module } if len(modules) > 0 { + sLog.InfofCtx(ctx, " P (IoT Edge Target): remove from IoT edge with modules count %d", len(modules)) err = i.remvoefromIoTEdge(ctx, deployment.Instance.ObjectMeta.Name, deployment.Instance.Spec.Metadata, modules, edgeAgent, edgeHub) if err != nil { sLog.ErrorfCtx(ctx, " P (IoT Edge Target): failed to remove from IoT edge: %+v", err) @@ -545,34 +550,36 @@ func (i *IoTEdgeTargetProvider) getIoTEdgeModuleTwin(ctx context.Context, id str defer observ_utils.CloseSpanWithError(span, &err) defer observ_utils.EmitUserDiagnosticsLogs(ctx, &err) + sLog.InfofCtx(ctx, " P (IoT Edge Target): start to get IoT Edge modules using url %v", url) + module := ModuleTwin{} sasToken := azureutils.CreateSASToken(fmt.Sprintf("%s/devices/%s", i.Config.IoTHub, i.Config.DeviceName), i.Config.KeyName, i.Config.Key) client := &http.Client{} req, err := http.NewRequest(http.MethodGet, url, nil) if err != nil { - sLog.ErrorfCtx(ctx, "failed to get IoT Edge modules: %v", err) + sLog.ErrorfCtx(ctx, " P (IoT Edge Target): failed to get IoT Edge modules: %v", err) return module, v1alpha2.NewCOAError(err, "failed to get IoT Edge modules", v1alpha2.InternalError) } req.Header.Set("Content-Type", "application/json") req.Header.Set("Authorization", sasToken) resp, err := client.Do(req) if err != nil { - sLog.ErrorfCtx(ctx, "failed to get IoT Edge modules: %v", err) + sLog.ErrorfCtx(ctx, " P (IoT Edge Target): failed to get IoT Edge modules: %v", err) return module, v1alpha2.NewCOAError(err, "failed to get IoT Edge modules", v1alpha2.InternalError) } if resp.StatusCode != http.StatusOK { - sLog.ErrorfCtx(ctx, "failed to get IoT Edge modules: %v", resp) + sLog.ErrorfCtx(ctx, " P (IoT Edge Target): failed to get IoT Edge modules: %v", resp) //return module, v1alpha1.NewCOAError(nil, "failed to get IoT Edge modules", v1alpha1.InternalError) //TODO: carry over HTTP status code } defer resp.Body.Close() bodyBytes, err := ioutil.ReadAll(resp.Body) if err != nil { - sLog.ErrorfCtx(ctx, "failed to get IoT Edge modules: %v", err) + sLog.ErrorfCtx(ctx, " P (IoT Edge Target): failed to get IoT Edge modules: %v", err) return module, v1alpha2.NewCOAError(err, "failed to get IoT Edge modules", v1alpha2.InternalError) } err = json.Unmarshal(bodyBytes, &module) if err != nil { - sLog.ErrorfCtx(ctx, "failed to get IoT Edge modules: %v", err) + sLog.ErrorfCtx(ctx, " P (IoT Edge Target): failed to get IoT Edge modules: %v", err) return module, v1alpha2.NewCOAError(err, "failed to get IoT Edge modules", v1alpha2.InternalError) } return module, nil @@ -596,8 +603,8 @@ func (i *IoTEdgeTargetProvider) getIoTEdgeModules(ctx context.Context) (map[stri } func (i *IoTEdgeTargetProvider) remvoefromIoTEdge(ctx context.Context, name string, metadata map[string]string, modules map[string]Module, agentRef ModuleTwin, hubRef ModuleTwin) error { - deployment := makeDefaultDeployment(metadata, i.Config.EdgeAgentVersion, i.Config.EdgeHubVersion) - err := reduceDeployment(&deployment, name, modules, agentRef, hubRef) + deployment := makeDefaultDeployment(ctx, metadata, i.Config.EdgeAgentVersion, i.Config.EdgeHubVersion) + err := reduceDeployment(ctx, &deployment, name, modules, agentRef, hubRef) if err != nil { return err } @@ -605,10 +612,9 @@ func (i *IoTEdgeTargetProvider) remvoefromIoTEdge(ctx context.Context, name stri } func (i *IoTEdgeTargetProvider) deployToIoTEdge(ctx context.Context, name string, metadata map[string]string, modules map[string]Module, agentRef ModuleTwin, hubRef ModuleTwin) error { + deployment := makeDefaultDeployment(ctx, metadata, i.Config.EdgeAgentVersion, i.Config.EdgeHubVersion) - deployment := makeDefaultDeployment(metadata, i.Config.EdgeAgentVersion, i.Config.EdgeHubVersion) - - err := updateDeployment(&deployment, name, modules, agentRef, hubRef) + err := updateDeployment(ctx, &deployment, name, modules, agentRef, hubRef) if err != nil { return err } @@ -630,23 +636,24 @@ func (i *IoTEdgeTargetProvider) applyIoTEdgeDeployment(ctx context.Context, depl client := &http.Client{} payload, err := json.Marshal(deployment) if err != nil { + sLog.ErrorfCtx(ctx, " P (IoT Edge Target): failed to marshall deployment: %v", err) return v1alpha2.NewCOAError(err, "failed to serialize IoT Edge deployemnt", v1alpha2.SerializationError) } req, err := http.NewRequest(http.MethodPost, url, bytes.NewBuffer(payload)) if err != nil { - sLog.ErrorfCtx(ctx, "failed to post IoT Edge deployment: %v", err) + sLog.ErrorfCtx(ctx, " P (IoT Edge Target): failed to post IoT Edge deployment: %v", err) return v1alpha2.NewCOAError(err, "failed to post IoT Edge deployment", v1alpha2.InternalError) } req.Header.Set("Content-Type", "application/json") req.Header.Set("Authorization", sasToken) resp, err := client.Do(req) if err != nil { - sLog.ErrorfCtx(ctx, "failed to post IoT Edge deployment: %v", err) + sLog.ErrorfCtx(ctx, " P (IoT Edge Target): failed to post IoT Edge deployment: %v", err) return v1alpha2.NewCOAError(err, "failed to post IoT Edge deployment", v1alpha2.InternalError) } if resp.StatusCode != http.StatusNoContent && resp.StatusCode != http.StatusOK { - sLog.ErrorfCtx(ctx, "failed to post IoT Edge deployment: %v", resp) + sLog.ErrorfCtx(ctx, " P (IoT Edge Target): failed to post IoT Edge deployment: %v", resp) return v1alpha2.NewCOAError(nil, "failed to post IoT Edge deployment", v1alpha2.InternalError) //TODO: carry over HTTP status code } return nil @@ -685,7 +692,8 @@ func carryOverRoutes(deployment *IoTEdgeDeployment, ref ModuleTwin) { } } -func updateDeployment(deployment *IoTEdgeDeployment, name string, modules map[string]Module, agentRef ModuleTwin, hubRef ModuleTwin) error { +func updateDeployment(ctx context.Context, deployment *IoTEdgeDeployment, name string, modules map[string]Module, agentRef ModuleTwin, hubRef ModuleTwin) error { + sLog.InfoCtx(ctx, " P (IoT Edge Target): reduceDeployment()") // add all other modules that are not in the current module list so that we can write them back otherModules := map[string]bool{} @@ -750,6 +758,7 @@ func updateDeployment(deployment *IoTEdgeDeployment, name string, modules map[st } return nil } + func modifyRoutes(route string, name string, modules map[string]Module, otherModules map[string]bool) string { for k, _ := range modules { if _, ok := otherModules[k]; !ok { @@ -759,8 +768,8 @@ func modifyRoutes(route string, name string, modules map[string]Module, otherMod return route } -func reduceDeployment(deployment *IoTEdgeDeployment, name string, modules map[string]Module, ref ModuleTwin, hubRef ModuleTwin) error { - +func reduceDeployment(ctx context.Context, deployment *IoTEdgeDeployment, name string, modules map[string]Module, ref ModuleTwin, hubRef ModuleTwin) error { + sLog.InfoCtx(ctx, " P (IoT Edge Target): reduceDeployment()") otherModules := map[string]bool{} rd := deployment.ModulesContent["$edgeHub"].DesiredProperties["routes"].(map[string]string) @@ -820,8 +829,7 @@ func reduceDeployment(deployment *IoTEdgeDeployment, name string, modules map[st return nil } -func makeDefaultDeployment(metadata map[string]string, edgeAgentVersion string, edgeHubVersion string) IoTEdgeDeployment { - +func makeDefaultDeployment(ctx context.Context, metadata map[string]string, edgeAgentVersion string, edgeHubVersion string) IoTEdgeDeployment { deployment := IoTEdgeDeployment{ ModulesContent: map[string]ModuleState{ "$edgeAgent": { @@ -871,6 +879,8 @@ func makeDefaultDeployment(metadata map[string]string, edgeAgentVersion string, err := json.Unmarshal(data, &credentials) if err == nil { (deployment.ModulesContent["$edgeAgent"].DesiredProperties["runtime"].(Runtime)).Settings["registryCredentials"] = credentials + } else { + sLog.ErrorfCtx(ctx, " P (IoT Edge Target): failed to unmarshall credentials: %v", err) } } return deployment diff --git a/api/pkg/apis/v1alpha1/providers/target/azure/iotedge/iotedge_test.go b/api/pkg/apis/v1alpha1/providers/target/azure/iotedge/iotedge_test.go index c17bc9be6..8cbc454fd 100644 --- a/api/pkg/apis/v1alpha1/providers/target/azure/iotedge/iotedge_test.go +++ b/api/pkg/apis/v1alpha1/providers/target/azure/iotedge/iotedge_test.go @@ -247,9 +247,9 @@ func TestToModuleEnvVariables(t *testing.T) { assert.Equal(t, "DEF", module.Environments["A2"].Value) } func TestUpdateDeployment(t *testing.T) { - deployment := makeDefaultDeployment(nil, "", "") + deployment := makeDefaultDeployment(context.Background(), nil, "", "") - updateDeployment(&deployment, "my-instance-1", map[string]Module{ + updateDeployment(context.Background(), &deployment, "my-instance-1", map[string]Module{ "my-module": { Settings: map[string]string{ "123": "ABC", @@ -262,9 +262,9 @@ func TestUpdateDeployment(t *testing.T) { assert.Equal(t, "ABC", col["my-instance-1-my-module"].Settings["123"]) } func TestUpdateDeploymentWithExistingModule(t *testing.T) { - deployment := makeDefaultDeployment(nil, "", "") + deployment := makeDefaultDeployment(context.Background(), nil, "", "") - updateDeployment(&deployment, "my-instance-1", map[string]Module{ + updateDeployment(context.Background(), &deployment, "my-instance-1", map[string]Module{ "my-module": { Settings: map[string]string{ "123": "ABC", @@ -292,9 +292,9 @@ func TestUpdateDeploymentWithExistingModule(t *testing.T) { } func TestUpdateDeploymentWithCurrentModule(t *testing.T) { - deployment := makeDefaultDeployment(nil, "", "") + deployment := makeDefaultDeployment(context.Background(), nil, "", "") - updateDeployment(&deployment, "my-instance-1", map[string]Module{ + updateDeployment(context.Background(), &deployment, "my-instance-1", map[string]Module{ "my-module": { Settings: map[string]string{ "123": "ABC", @@ -320,9 +320,9 @@ func TestUpdateDeploymentWithCurrentModule(t *testing.T) { assert.Equal(t, "ABC", col["my-instance-1-my-module"].Settings["123"]) } func TestReduceDeploymentWithCurrentModule(t *testing.T) { - deployment := makeDefaultDeployment(nil, "", "") + deployment := makeDefaultDeployment(context.Background(), nil, "", "") - reduceDeployment(&deployment, "my-instance-1", map[string]Module{ + reduceDeployment(context.Background(), &deployment, "my-instance-1", map[string]Module{ "my-module": { Settings: map[string]string{ "123": "ABC", @@ -347,9 +347,9 @@ func TestReduceDeploymentWithCurrentModule(t *testing.T) { assert.Equal(t, 0, len(col)) } func TestReduceDeploymentWithMoreModule(t *testing.T) { - deployment := makeDefaultDeployment(nil, "", "") + deployment := makeDefaultDeployment(context.Background(), nil, "", "") - reduceDeployment(&deployment, "my-instance-1", map[string]Module{ + reduceDeployment(context.Background(), &deployment, "my-instance-1", map[string]Module{ "my-module": { Settings: map[string]string{ "123": "ABC", @@ -416,9 +416,9 @@ func TestModifyRoutesHitOther(t *testing.T) { assert.Equal(t, "FROM /messages/modules/my-instance-1-SimulatedTemperatureSensor/outputs/temperatureOutput INTO BrokeredEndpoint(\"/modules/filtermodule/inputs/input1\")", route) } func TestUpdateDeploymentWithRoutes(t *testing.T) { - deployment := makeDefaultDeployment(nil, "", "") + deployment := makeDefaultDeployment(context.Background(), nil, "", "") - updateDeployment(&deployment, "my-instance-1", map[string]Module{ + updateDeployment(context.Background(), &deployment, "my-instance-1", map[string]Module{ "my-module": { Settings: map[string]string{ "123": "ABC", @@ -435,9 +435,9 @@ func TestUpdateDeploymentWithRoutes(t *testing.T) { assert.Equal(t, "FROM messagees/modules/my-instance-1-my-module INTO messages/modules/other", col2["my-instance-1-route-1"]) } func TestUpdateDeploymentWithExistingModuleAndRoute(t *testing.T) { - deployment := makeDefaultDeployment(nil, "", "") + deployment := makeDefaultDeployment(context.Background(), nil, "", "") - updateDeployment(&deployment, "my-instance-1", map[string]Module{ + updateDeployment(context.Background(), &deployment, "my-instance-1", map[string]Module{ "my-module": { Settings: map[string]string{ "123": "ABC", @@ -474,9 +474,9 @@ func TestUpdateDeploymentWithExistingModuleAndRoute(t *testing.T) { assert.Equal(t, "FROM messagees/modules/other-module INTO messages/modules/another", col2["route-1"]) } func TestUpdateDeploymentWithCurrentModuleAndRoutes(t *testing.T) { - deployment := makeDefaultDeployment(nil, "", "") + deployment := makeDefaultDeployment(context.Background(), nil, "", "") - updateDeployment(&deployment, "my-instance-1", map[string]Module{ + updateDeployment(context.Background(), &deployment, "my-instance-1", map[string]Module{ "my-module": { Settings: map[string]string{ "123": "ABC", @@ -512,9 +512,9 @@ func TestUpdateDeploymentWithCurrentModuleAndRoutes(t *testing.T) { assert.Equal(t, "FROM messagees/modules/my-instance-1-my-module INTO messages/modules/cool", col2["my-instance-1-route-1"]) } func TestReduceDeploymentWithCurrentModuleRoute(t *testing.T) { - deployment := makeDefaultDeployment(nil, "", "") + deployment := makeDefaultDeployment(context.Background(), nil, "", "") - reduceDeployment(&deployment, "my-instance-1", map[string]Module{ + reduceDeployment(context.Background(), &deployment, "my-instance-1", map[string]Module{ "my-module": { Settings: map[string]string{ "123": "ABC", @@ -550,9 +550,9 @@ func TestReduceDeploymentWithCurrentModuleRoute(t *testing.T) { assert.Equal(t, 0, len(col2)) } func TestReduceDeploymentWithMoreModuleAndRoutes(t *testing.T) { - deployment := makeDefaultDeployment(nil, "", "") + deployment := makeDefaultDeployment(context.Background(), nil, "", "") - reduceDeployment(&deployment, "my-instance-1", map[string]Module{ + reduceDeployment(context.Background(), &deployment, "my-instance-1", map[string]Module{ "my-module": { Settings: map[string]string{ "123": "ABC", diff --git a/api/pkg/apis/v1alpha1/providers/target/configmap/configmap.go b/api/pkg/apis/v1alpha1/providers/target/configmap/configmap.go index 80d6fbbc5..cbc91b29c 100644 --- a/api/pkg/apis/v1alpha1/providers/target/configmap/configmap.go +++ b/api/pkg/apis/v1alpha1/providers/target/configmap/configmap.go @@ -105,7 +105,7 @@ func (s *ConfigMapTargetProvider) SetContext(ctx *contexts.ManagerContext) { func (i *ConfigMapTargetProvider) InitWithMap(properties map[string]string) error { config, err := ConfigMapTargetProviderConfigFromMap(properties) if err != nil { - sLog.Errorf(" P (ConfigMap Target): expected ConfigMapTargetProviderConfig %+v", err) + sLog.Errorf(" P (ConfigMap Target): expected ConfigMapTargetProviderConfig: %+v", err) return err } @@ -252,6 +252,7 @@ func (i *ConfigMapTargetProvider) Get(ctx context.Context, deployment model.Depl component.Component.Properties[key] = value } } + sLog.InfofCtx(ctx, " P (ConfigMap Target): append component: %s", component.Component.Name) ret = append(ret, component.Component) } @@ -271,13 +272,14 @@ func (i *ConfigMapTargetProvider) Apply(ctx context.Context, deployment model.De defer utils.CloseSpanWithError(span, &err) defer utils.EmitUserDiagnosticsLogs(ctx, &err) - sLog.InfofCtx(ctx, " P (ConfigMap Target): applying artifacts: %s - %s", deployment.Instance.Spec.Scope, deployment.Instance.ObjectMeta.Name) + sLog.InfofCtx(ctx, " P (ConfigMap Target): applying artifacts: %s - %s", deployment.Instance.Spec.Scope, deployment.Instance.ObjectMeta.Name) functionName := utils.GetFunctionName() applyTime := time.Now().UTC() components := step.GetComponents() err = i.GetValidationRule(ctx).Validate(components) if err != nil { + sLog.ErrorfCtx(ctx, " P (ConfigMap Target): failed to validate components: %+v", err) providerOperationMetrics.ProviderOperationErrors( configmap, functionName, @@ -288,6 +290,7 @@ func (i *ConfigMapTargetProvider) Apply(ctx context.Context, deployment model.De return nil, err } if isDryRun { + sLog.DebugCtx(ctx, " P (ConfigMap Target): dryRun is enabled, skipping apply") err = nil return nil, nil } @@ -295,6 +298,7 @@ func (i *ConfigMapTargetProvider) Apply(ctx context.Context, deployment model.De ret := step.PrepareResultMap() components = step.GetUpdatedComponents() if len(components) > 0 { + sLog.InfofCtx(ctx, " P (ConfigMap Target): get updated components: count - %d", len(components)) for _, component := range components { if component.Type == "config" { newConfigMap := &corev1.ConfigMap{ @@ -338,6 +342,7 @@ func (i *ConfigMapTargetProvider) Apply(ctx context.Context, deployment model.De deleteTime := time.Now().UTC() components = step.GetDeletedComponents() if len(components) > 0 { + sLog.InfofCtx(ctx, " P (ConfigMap Target): get deleted components: count - %d", len(components)) for _, component := range components { if component.Type == "config" { err = i.deleteConfigMap(ctx, component.Name, deployment.Instance.Spec.Scope) @@ -399,7 +404,7 @@ func (k *ConfigMapTargetProvider) ensureNamespace(ctx context.Context, namespace return err } } else { - sLog.ErrorfCtx(ctx, " P (ConfigMap Target): failed to get namespace: %+v", err) + sLog.ErrorfCtx(ctx, " P (ConfigMap Target): failed to get namespace %s: %+v", namespace, err) return err } diff --git a/api/pkg/apis/v1alpha1/providers/target/docker/docker.go b/api/pkg/apis/v1alpha1/providers/target/docker/docker.go index 0819396d7..2e404abda 100644 --- a/api/pkg/apis/v1alpha1/providers/target/docker/docker.go +++ b/api/pkg/apis/v1alpha1/providers/target/docker/docker.go @@ -51,6 +51,7 @@ func DockerTargetProviderConfigFromMap(properties map[string]string) (DockerTarg func (d *DockerTargetProvider) InitWithMap(properties map[string]string) error { config, err := DockerTargetProviderConfigFromMap(properties) if err != nil { + sLog.Errorf(" P (Docker Target): expected DockerTargetProviderConfigFromMap: %+v", err) return err } return d.Init(config) @@ -162,7 +163,10 @@ func (i *DockerTargetProvider) Get(ctx context.Context, deployment model.Deploym } } } + sLog.InfofCtx(ctx, " P (Docker Target): append component: %s", component.Name) ret = append(ret, component) + } else { + sLog.ErrorfCtx(ctx, " P (Docker Target): failed to get container info: %+v", err) } } @@ -192,6 +196,7 @@ func (i *DockerTargetProvider) Apply(ctx context.Context, deployment model.Deplo return nil, err } if isDryRun { + sLog.DebugCtx(ctx, " P (Docker Target): dryRun is enabled, skipping apply") err = nil return nil, nil } @@ -240,6 +245,7 @@ func (i *DockerTargetProvider) Apply(ctx context.Context, deployment model.Deplo sLog.ErrorfCtx(ctx, " P (Docker Target): failed to stop a running container: %+v", err) return ret, err } + sLog.DebugfCtx(ctx, " P (Docker Target): container %s is not found", component.Component.Name) } err = cli.ContainerRemove(ctx, component.Component.Name, container.RemoveOptions{}) if err != nil { @@ -281,6 +287,7 @@ func (i *DockerTargetProvider) Apply(ctx context.Context, deployment model.Deplo } } var containerResponse container.CreateResponse + sLog.InfofCtx(ctx, " P (Docker Target): create container: %s", component.Component.Name) containerResponse, err = cli.ContainerCreate(ctx, &containerConfig, hostConfig, nil, nil, component.Component.Name) if err != nil { ret[component.Component.Name] = model.ComponentResultSpec{ @@ -291,6 +298,7 @@ func (i *DockerTargetProvider) Apply(ctx context.Context, deployment model.Deplo return ret, err } + sLog.InfofCtx(ctx, " P (Docker Target): start container: %s", component.Component.Name) if err = cli.ContainerStart(ctx, containerResponse.ID, container.StartOptions{}); err != nil { ret[component.Component.Name] = model.ComponentResultSpec{ Status: v1alpha2.UpdateFailed, @@ -304,19 +312,24 @@ func (i *DockerTargetProvider) Apply(ctx context.Context, deployment model.Deplo Message: "", } } else { + sLog.InfofCtx(ctx, " P (Docker Target): stop container: %s", component.Component.Name) err = cli.ContainerStop(ctx, component.Component.Name, container.StopOptions{}) if err != nil { if !client.IsErrNotFound(err) { sLog.ErrorfCtx(ctx, " P (Docker Target): failed to stop a running container: %+v", err) return ret, err } + sLog.DebugfCtx(ctx, " P (Docker Target): container %s is not found", component.Component.Name) } + + sLog.InfofCtx(ctx, " P (Docker Target): remove container: %s", component.Component.Name) err = cli.ContainerRemove(ctx, component.Component.Name, container.RemoveOptions{}) if err != nil { if !client.IsErrNotFound(err) { sLog.ErrorfCtx(ctx, " P (Docker Target): failed to remove existing container: %+v", err) return ret, err } + sLog.DebugfCtx(ctx, " P (Docker Target): container %s is not found", component.Component.Name) } ret[component.Component.Name] = model.ComponentResultSpec{ Status: v1alpha2.Deleted, diff --git a/api/pkg/apis/v1alpha1/providers/target/helm/helm.go b/api/pkg/apis/v1alpha1/providers/target/helm/helm.go index 80bf19e47..193d53082 100644 --- a/api/pkg/apis/v1alpha1/providers/target/helm/helm.go +++ b/api/pkg/apis/v1alpha1/providers/target/helm/helm.go @@ -128,6 +128,7 @@ func HelmTargetProviderConfigFromMap(properties map[string]string) (HelmTargetPr func (i *HelmTargetProvider) InitWithMap(properties map[string]string) error { config, err := HelmTargetProviderConfigFromMap(properties) if err != nil { + sLog.Errorf(" P (ConfigMap Target): expected HelmTargetProviderConfigFromMap: %+v", err) return v1alpha2.NewCOAError(err, fmt.Sprintf("%s: failed to init", providerName), v1alpha2.InitFailed) } @@ -422,6 +423,7 @@ func (i *HelmTargetProvider) Apply(ctx context.Context, deployment model.Deploym } if isDryRun { + sLog.DebugCtx(ctx, " P (Helm Target): dryRun is enabled, skipping apply") return nil, nil } @@ -430,7 +432,7 @@ func (i *HelmTargetProvider) Apply(ctx context.Context, deployment model.Deploym var actionConfig *action.Configuration actionConfig, err = i.createActionConfig(ctx, deployment.Instance.Spec.Scope) if err != nil { - sLog.ErrorCtx(ctx, err) + sLog.ErrorfCtx(ctx, " P (Helm Target): failed to create action config: %+v", err) providerOperationMetrics.ProviderOperationErrors( helm, functionName, @@ -513,16 +515,19 @@ func (i *HelmTargetProvider) Apply(ctx context.Context, deployment model.Deploym } installClient, err := configureInstallClient(ctx, component.Component.Name, &helmProp.Chart, &deployment, actionConfig, postRender) if err != nil { + sLog.ErrorfCtx(ctx, " P (Helm Target): failed to config helm install client: %+v", err) return nil, err } upgradeClient, err := configureUpgradeClient(ctx, &helmProp.Chart, &deployment, actionConfig, postRender) if err != nil { + sLog.ErrorfCtx(ctx, " P (Helm Target): failed to config helm upgrade client: %+v", err) return nil, err } utils.EmitUserAuditsLogs(ctx, " P (Helm Target): Applying chart name: %s, chart: {repo: %s, name: %s, version: %s}, namespace: %s", component.Component.Name, helmProp.Chart.Repo, helmProp.Chart.Name, helmProp.Chart.Version, deployment.Instance.Spec.Scope) if _, err = upgradeClient.Run(component.Component.Name, chart, helmProp.Values); err != nil { + sLog.InfofCtx(ctx, " P (Helm Target): cannot update chart and use install client: %+v", err) if _, err = installClient.Run(chart, helmProp.Values); err != nil { - sLog.ErrorfCtx(ctx, " P (Helm Target): failed to apply: %+v", err) + sLog.ErrorfCtx(ctx, " P (Helm Target): failed to apply chart: %+v", err) err = v1alpha2.NewCOAError(err, fmt.Sprintf("%s: failed to apply chart", providerName), v1alpha2.HelmActionFailed) ret[component.Component.Name] = model.ComponentResultSpec{ Status: v1alpha2.UpdateFailed, @@ -540,6 +545,7 @@ func (i *HelmTargetProvider) Apply(ctx context.Context, deployment model.Deploym } } + sLog.InfofCtx(ctx, " P (Helm Target): apply chart successfully: %s", component.Component.Name) ret[component.Component.Name] = model.ComponentResultSpec{ Status: v1alpha2.Updated, Message: fmt.Sprintf("No error. %s has been updated", component.Component.Name), @@ -557,6 +563,7 @@ func (i *HelmTargetProvider) Apply(ctx context.Context, deployment model.Deploym case "helm.v3": uninstallClient, err := configureUninstallClient(ctx, &helmProp.Chart, &deployment, actionConfig) if err != nil { + sLog.ErrorfCtx(ctx, " P (Helm Target): failed to configure uninstall client: %+v", err) return nil, err } utils.EmitUserAuditsLogs(ctx, " P (Helm Target): Uninstalling chart name: %s, namespace: %s", component.Component.Name, deployment.Instance.Spec.Scope) @@ -579,12 +586,13 @@ func (i *HelmTargetProvider) Apply(ctx context.Context, deployment model.Deploym return ret, err } + sLog.InfofCtx(ctx, " P (Helm Target): uninstall chart successfully: %s", component.Component.Name) ret[component.Component.Name] = model.ComponentResultSpec{ Status: v1alpha2.Deleted, Message: "", } default: - sLog.ErrorfCtx(ctx, " P (Helm Target): Failed to apply as %v is an invalid helm version", component.Component.Type) + sLog.ErrorfCtx(ctx, " P (Helm Target): Failed to uninstall helm chart as %v is an invalid helm version", component.Component.Type) } } @@ -690,6 +698,7 @@ func pullOCIChart(ctx context.Context, repo, version string) (*registry.PullResu } func configureInstallClient(ctx context.Context, name string, componentProps *HelmChartProperty, deployment *model.DeploymentSpec, config *action.Configuration, postRenderer postrender.PostRenderer) (*action.Install, error) { + sLog.InfofCtx(ctx, " P (Helm Target): start configuring install client in the namespace %s", deployment.Instance.Spec.Scope) installClient := action.NewInstall(config) installClient.ReleaseName = name if deployment.Instance.Spec.Scope == "" { @@ -716,6 +725,7 @@ func configureInstallClient(ctx context.Context, name string, componentProps *He } func configureUpgradeClient(ctx context.Context, componentProps *HelmChartProperty, deployment *model.DeploymentSpec, config *action.Configuration, postRenderer postrender.PostRenderer) (*action.Upgrade, error) { + sLog.InfofCtx(ctx, " P (Helm Target): start configuring upgrade client in the namespace %s", deployment.Instance.Spec.Scope) upgradeClient := action.NewUpgrade(config) upgradeClient.Wait = componentProps.Wait if componentProps.Timeout != "" { @@ -739,6 +749,7 @@ func configureUpgradeClient(ctx context.Context, componentProps *HelmChartProper } func configureUninstallClient(ctx context.Context, componentProps *HelmChartProperty, deployment *model.DeploymentSpec, config *action.Configuration) (*action.Uninstall, error) { + sLog.InfofCtx(ctx, " P (Helm Target): start configuring uninstall client in the namespace %s", deployment.Instance.Spec.Scope) uninstallClient := action.NewUninstall(config) uninstallClient.Wait = componentProps.Wait if componentProps.Timeout != "" { @@ -759,7 +770,7 @@ func convertTimeout(ctx context.Context, timeout string) (time.Duration, error) } if duration < 0 { sLog.ErrorfCtx(ctx, " P (Helm Target): Timeout is negative: %s", timeout) - return 0, errors.New("Timeout can not be negative.") + return 0, errors.New("timeout can not be negative") } return duration, nil } diff --git a/api/pkg/apis/v1alpha1/providers/target/helm/helm_test.go b/api/pkg/apis/v1alpha1/providers/target/helm/helm_test.go index 11181e271..9ff3ff577 100644 --- a/api/pkg/apis/v1alpha1/providers/target/helm/helm_test.go +++ b/api/pkg/apis/v1alpha1/providers/target/helm/helm_test.go @@ -663,8 +663,8 @@ func TestHelmTargetProviderWithNegativeTimeout(t *testing.T) { } _, err = provider.Apply(context.Background(), deployment, step, false) fmt.Printf("error timeout %v", err.Error()) - if !strings.Contains(err.Error(), "Timeout can not be negative") { - t.Errorf("expected error to contain 'Timeout can not be negative', but got %s", err.Error()) + if !strings.Contains(err.Error(), "timeout can not be negative") { + t.Errorf("expected error to contain 'timeout can not be negative', but got %s", err.Error()) } assert.NotNil(t, err) } diff --git a/api/pkg/apis/v1alpha1/providers/target/http/http.go b/api/pkg/apis/v1alpha1/providers/target/http/http.go index d9fb80347..56d88578e 100644 --- a/api/pkg/apis/v1alpha1/providers/target/http/http.go +++ b/api/pkg/apis/v1alpha1/providers/target/http/http.go @@ -60,6 +60,7 @@ func HttpTargetProviderConfigFromMap(properties map[string]string) (HttpTargetPr func (i *HttpTargetProvider) InitWithMap(properties map[string]string) error { config, err := HttpTargetProviderConfigFromMap(properties) if err != nil { + sLog.Errorf(" P (HTTP Target): expected HttpTargetProviderConfig: %+v", err) return err } return i.Init(config) @@ -153,6 +154,7 @@ func (i *HttpTargetProvider) Apply(ctx context.Context, deployment model.Deploym return nil, err } if isDryRun { + sLog.DebugCtx(ctx, " P (HTTP Target): dryRun is enabled, skipping apply") err = nil return nil, nil } @@ -164,6 +166,9 @@ func (i *HttpTargetProvider) Apply(ctx context.Context, deployment model.Deploym url := model.ReadPropertyCompat(component.Component.Properties, "http.url", injections) method := model.ReadPropertyCompat(component.Component.Properties, "http.method", injections) + sLog.InfofCtx(ctx, " P (HTTP Target): start to send request to %s", url) + utils.EmitUserAuditsLogs(ctx, fmt.Sprintf(" P (HTTP Target): Start to send request to %s", url)) + if url == "" { err = errors.New("component doesn't have a http.url property") ret[component.Component.Name] = model.ComponentResultSpec{ @@ -185,7 +190,6 @@ func (i *HttpTargetProvider) Apply(ctx context.Context, deployment model.Deploym } jsonData := []byte(body) var request *http.Request - utils.EmitUserAuditsLogs(ctx, fmt.Sprintf(" P (HTTP Target): Start to send request to %s", url)) request, err = http.NewRequest(method, url, bytes.NewBuffer(jsonData)) if err != nil { ret[component.Component.Name] = model.ComponentResultSpec{ @@ -212,7 +216,7 @@ func (i *HttpTargetProvider) Apply(ctx context.Context, deployment model.Deploym Status: v1alpha2.UpdateFailed, Message: err.Error(), } - sLog.ErrorfCtx(ctx, " P (HTTP Target): %v", err) + sLog.ErrorfCtx(ctx, " P (HTTP Target): failed to process http request: %v", err) providerOperationMetrics.ProviderOperationErrors( httpProvider, functionName, @@ -226,6 +230,7 @@ func (i *HttpTargetProvider) Apply(ctx context.Context, deployment model.Deploym bodyBytes, err := io.ReadAll(resp.Body) var message string if err != nil { + sLog.ErrorfCtx(ctx, " P (HTTP Target): failed to read response body: %v", err) message = err.Error() } else { message = string(bodyBytes) @@ -250,6 +255,8 @@ func (i *HttpTargetProvider) Apply(ctx context.Context, deployment model.Deploym Status: v1alpha2.Updated, Message: "HTTP request succeeded", } + } else { + sLog.InfofCtx(ctx, " P (HTTP Target): component %s is not in update action, skipping", component.Component.Name) } } providerOperationMetrics.ProviderOperationLatency( diff --git a/api/pkg/apis/v1alpha1/providers/target/ingress/ingress.go b/api/pkg/apis/v1alpha1/providers/target/ingress/ingress.go index 3f03352cb..6fd3000c7 100644 --- a/api/pkg/apis/v1alpha1/providers/target/ingress/ingress.go +++ b/api/pkg/apis/v1alpha1/providers/target/ingress/ingress.go @@ -111,6 +111,7 @@ func (s *IngressTargetProvider) SetContext(ctx *contexts.ManagerContext) { func (i *IngressTargetProvider) InitWithMap(properties map[string]string) error { config, err := IngressTargetProviderConfigFromMap(properties) if err != nil { + sLog.Errorf(" P (Ingress Target): expected IngressTargetProviderConfig: %+v", err) return err } @@ -241,7 +242,7 @@ func (i *IngressTargetProvider) Get(ctx context.Context, deployment model.Deploy obj, err = i.Client.NetworkingV1().Ingresses(deployment.Instance.Spec.Scope).Get(ctx, component.Component.Name, metav1.GetOptions{}) if err != nil { if kerrors.IsNotFound(err) { - sLog.InfofCtx(ctx, " P (Ingress Target): resource not found: %v", err) + sLog.InfofCtx(ctx, " P (Ingress Target): resource %s not found: %v", component.Component.Name, err) continue } sLog.ErrorfCtx(ctx, " P (Ingress Target): failed to read object: %+v", err) @@ -250,6 +251,7 @@ func (i *IngressTargetProvider) Get(ctx context.Context, deployment model.Deploy component.Component.Properties = make(map[string]interface{}) component.Component.Properties["rules"] = obj.Spec.Rules + sLog.InfofCtx(ctx, " P (Ingress Target): append component: %s", component.Component.Name) ret = append(ret, component.Component) } @@ -287,12 +289,14 @@ func (i *IngressTargetProvider) Apply(ctx context.Context, deployment model.Depl return nil, err } if isDryRun { + sLog.DebugCtx(ctx, " P (Ingress Target): dryRun is enabled, skipping apply") return nil, nil } ret := step.PrepareResultMap() components = step.GetUpdatedComponents() if len(components) > 0 { + sLog.InfofCtx(ctx, " P (Ingress Target): get updated components: count - %d", len(components)) for _, component := range components { if component.Type == "ingress" { newIngress := &networkingv1.Ingress{ @@ -377,6 +381,7 @@ func (i *IngressTargetProvider) Apply(ctx context.Context, deployment model.Depl deleteTime := time.Now().UTC() components = step.GetDeletedComponents() if len(components) > 0 { + sLog.InfofCtx(ctx, " P (Ingress Target): get deleted components: count - %d", len(components)) for _, component := range components { if component.Type == "ingress" { err = i.deleteIngress(ctx, component.Name, deployment.Instance.Spec.Scope) @@ -425,6 +430,7 @@ func (k *IngressTargetProvider) ensureNamespace(ctx context.Context, namespace s } if kerrors.IsNotFound(err) { + sLog.InfofCtx(ctx, " P (Ingress Target): start to create namespace %s", namespace) utils.EmitUserAuditsLogs(ctx, " P (Ingress Target): Start to create namespace - %s", namespace) _, err = k.Client.CoreV1().Namespaces().Create(ctx, &corev1.Namespace{ ObjectMeta: metav1.ObjectMeta{ @@ -487,6 +493,8 @@ func (i *IngressTargetProvider) deleteIngress(ctx context.Context, name string, if !kerrors.IsNotFound(err) { sLog.ErrorfCtx(ctx, " P (Ingress Target): failed to delete ingress: %+v", err) return err + } else { + sLog.InfoCtx(ctx, " P (Ingress Target): ingress %s is not found in the namespace %s", name, namespace) } } return nil @@ -518,10 +526,11 @@ func (i *IngressTargetProvider) applyIngress(ctx context.Context, ingress *netwo } return nil } - sLog.ErrorfCtx(ctx, " P (Ingress Target): failed to read object: %+v", err) + sLog.ErrorfCtx(ctx, " P (Ingress Target): failed to read object %s in the namespace %s: %+v", ingress.Name, namespace, err) return err } + sLog.InfofCtx(ctx, " P (Ingress Target): resource exists and start to update ingress %s in the namespace", ingress.Name, namespace) existingIngress.Spec.Rules = ingress.Spec.Rules if ingress.ObjectMeta.Annotations != nil { existingIngress.ObjectMeta.Annotations = ingress.ObjectMeta.Annotations diff --git a/api/pkg/apis/v1alpha1/providers/target/k8s/k8s.go b/api/pkg/apis/v1alpha1/providers/target/k8s/k8s.go index f4435511c..2cb96a2fa 100644 --- a/api/pkg/apis/v1alpha1/providers/target/k8s/k8s.go +++ b/api/pkg/apis/v1alpha1/providers/target/k8s/k8s.go @@ -49,7 +49,7 @@ const ( SERVICES string = "services" SERVICES_NS string = "ns-services" SERVICES_HNS string = "hns-services" //TODO: future versions - componentName string = "P (K8s Target Provider)" + componentName string = "P (K8s Target)" loggerName string = "providers.target.k8s" k8s string = "k8s" ) @@ -142,6 +142,7 @@ func K8sTargetProviderConfigFromMap(properties map[string]string) (K8sTargetProv func (i *K8sTargetProvider) InitWithMap(properties map[string]string) error { config, err := K8sTargetProviderConfigFromMap(properties) if err != nil { + log.Errorf(" P (K8s Target): expected K8sTargetProviderConfig: %+v", err) return v1alpha2.NewCOAError(err, fmt.Sprintf("%s: failed to init", componentName), v1alpha2.InitFailed) } return i.Init(config) @@ -252,7 +253,7 @@ func (i *K8sTargetProvider) getDeployment(ctx context.Context, namespace string, var err error = nil defer observ_utils.CloseSpanWithError(span, &err) defer observ_utils.EmitUserDiagnosticsLogs(ctx, &err) - log.InfofCtx(ctx, " P (K8s Target Provider): getDeployment scope - %s, name - %s", namespace, name) + log.InfofCtx(ctx, " P (K8s Target): getDeployment scope - %s, name - %s", namespace, name) if namespace == "" { namespace = "default" @@ -263,12 +264,12 @@ func (i *K8sTargetProvider) getDeployment(ctx context.Context, namespace string, if k8s_errors.IsNotFound(err) { return nil, nil } - log.ErrorfCtx(ctx, " P (K8s Target Provider): getDeployment %s failed - %s", name, err.Error()) + log.ErrorfCtx(ctx, " P (K8s Target): getDeployment %s failed - %s", name, err.Error()) return nil, err } components, err := deploymentToComponents(ctx, *deployment) if err != nil { - log.ErrorfCtx(ctx, " P (K8s Target Provider): getDeployment failed - %s", err.Error()) + log.ErrorfCtx(ctx, " P (K8s Target): getDeployment failed - %s", err.Error()) return nil, err } return components, nil @@ -308,7 +309,7 @@ func (i *K8sTargetProvider) Get(ctx context.Context, dep model.DeploymentSpec, r var err error = nil defer observ_utils.CloseSpanWithError(span, &err) defer observ_utils.EmitUserDiagnosticsLogs(ctx, &err) - log.InfofCtx(ctx, " P (K8s Target Provider): getting artifacts: %s - %s", dep.Instance.Spec.Scope, dep.Instance.ObjectMeta.Name) + log.InfofCtx(ctx, " P (K8s Target): getting artifacts: %s - %s", dep.Instance.Spec.Scope, dep.Instance.ObjectMeta.Name) var components []model.ComponentSpec @@ -316,7 +317,7 @@ func (i *K8sTargetProvider) Get(ctx context.Context, dep model.DeploymentSpec, r case "", SINGLE_POD: components, err = i.getDeployment(ctx, dep.Instance.Spec.Scope, dep.Instance.ObjectMeta.Name) if err != nil { - log.DebugfCtx(ctx, " P (K8s Target Provider): failed to get - %s", err.Error()) + log.DebugfCtx(ctx, " P (K8s Target): failed to get - %s", err.Error()) err = v1alpha2.NewCOAError(err, fmt.Sprintf("%s: failed to get components from deployment spec", componentName), v1alpha2.GetComponentSpecFailed) return nil, err } @@ -331,12 +332,12 @@ func (i *K8sTargetProvider) Get(ctx context.Context, dep model.DeploymentSpec, r var cComponents []model.ComponentSpec cComponents, err = i.getDeployment(ctx, scope, component.Name) if err != nil { - log.DebugfCtx(ctx, " P (K8s Target Provider): failed to get deployment: %s", err.Error()) + log.DebugfCtx(ctx, " P (K8s Target): failed to get deployment: %s", err.Error()) err = v1alpha2.NewCOAError(err, fmt.Sprintf("%s: failed to get components from deployment spec", componentName), v1alpha2.GetComponentSpecFailed) return nil, err } if len(cComponents) > 1 { - log.DebugfCtx(ctx, " P (K8s Target Provider): can't read multiple components %s", err.Error()) + log.DebugfCtx(ctx, " P (K8s Target): can't read multiple components %s", err.Error()) err = v1alpha2.NewCOAError(nil, fmt.Sprintf("%s: can't read multiple components when %s strategy or %s strategy is used", componentName, SERVICES, SERVICES_NS), v1alpha2.GetComponentSpecFailed) return nil, err } @@ -354,7 +355,7 @@ func (i *K8sTargetProvider) Get(ctx context.Context, dep model.DeploymentSpec, r err = i.fillServiceMeta(ctx, scope, serviceName, cComponents[0]) if err != nil { - log.DebugfCtx(ctx, " P (K8s Target Provider): failed to get: %s", err.Error()) + log.DebugfCtx(ctx, " P (K8s Target): failed to get: %s", err.Error()) err = v1alpha2.NewCOAError(err, fmt.Sprintf("%s: failed to fill service meta data", componentName), v1alpha2.GetComponentSpecFailed) return nil, err } @@ -372,7 +373,7 @@ func (i *K8sTargetProvider) removeService(ctx context.Context, namespace string, var err error = nil defer observ_utils.CloseSpanWithError(span, &err) defer observ_utils.EmitUserDiagnosticsLogs(ctx, &err) - log.InfofCtx(ctx, " P (K8s Target Provider): removeService namespace - %s, serviceName - %s", namespace, serviceName) + log.InfofCtx(ctx, " P (K8s Target): removeService namespace - %s, serviceName - %s", namespace, serviceName) if namespace == "" { namespace = "default" @@ -397,14 +398,14 @@ func (i *K8sTargetProvider) removeDeployment(ctx context.Context, namespace stri var err error = nil defer observ_utils.CloseSpanWithError(span, &err) defer observ_utils.EmitUserDiagnosticsLogs(ctx, &err) - log.InfofCtx(ctx, " P (K8s Target Provider): removeDeployment namespace - %s, name - %s", namespace, name) + log.InfofCtx(ctx, " P (K8s Target): removeDeployment namespace - %s, name - %s", namespace, name) if namespace == "" { namespace = "default" } foregroundDeletion := metav1.DeletePropagationForeground - observ_utils.EmitUserAuditsLogs(ctx, " P (K8s Target Provider): Start to remove deployment under namespace - %s, name - %s", namespace, name) + observ_utils.EmitUserAuditsLogs(ctx, " P (K8s Target): Start to remove deployment under namespace - %s, name - %s", namespace, name) err = i.Client.AppsV1().Deployments(namespace).Delete(ctx, name, metav1.DeleteOptions{PropagationPolicy: &foregroundDeletion}) if err != nil { if !k8s_errors.IsNotFound(err) { @@ -421,7 +422,7 @@ func (i *K8sTargetProvider) removeNamespace(ctx context.Context, namespace strin var err error = nil defer observ_utils.CloseSpanWithError(span, &err) defer observ_utils.EmitUserDiagnosticsLogs(ctx, &err) - log.InfofCtx(ctx, " P (K8s Target Provider): removeNamespace namespace - %s", namespace) + log.InfofCtx(ctx, " P (K8s Target): removeNamespace namespace - %s", namespace) _, err = i.Client.CoreV1().Namespaces().Get(ctx, namespace, metav1.GetOptions{}) if err != nil { @@ -487,14 +488,14 @@ func (i *K8sTargetProvider) removeNamespace(ctx context.Context, namespace strin isEmpty := true for resource, count := range resourceCount { if count != 0 { - log.DebugfCtx(ctx, " P (K8s Target Provider): failed to delete %s namespace as resource %s is not empty", namespace, resource) + log.DebugfCtx(ctx, " P (K8s Target): failed to delete %s namespace as resource %s is not empty", namespace, resource) isEmpty = false break } } if isEmpty { - observ_utils.EmitUserAuditsLogs(ctx, " P (K8s Target Provider): Start to remove namespace - %s", namespace) + observ_utils.EmitUserAuditsLogs(ctx, " P (K8s Target): Start to remove namespace - %s", namespace) err = i.Client.CoreV1().Namespaces().Delete(ctx, namespace, metav1.DeleteOptions{}) if err != nil { return err @@ -509,7 +510,7 @@ func (i *K8sTargetProvider) createNamespace(ctx context.Context, namespace strin var err error = nil defer observ_utils.CloseSpanWithError(span, &err) defer observ_utils.EmitUserDiagnosticsLogs(ctx, &err) - log.InfofCtx(ctx, " P (K8s Target Provider): removeDeployment namespace - %s", namespace) + log.InfofCtx(ctx, " P (K8s Target): removeDeployment namespace - %s", namespace) if namespace == "" || namespace == "default" { return nil @@ -518,7 +519,7 @@ func (i *K8sTargetProvider) createNamespace(ctx context.Context, namespace strin if err != nil { if k8s_errors.IsNotFound(err) { - observ_utils.EmitUserAuditsLogs(ctx, " P (K8s Target Provider): Start to create namespace - %s", namespace) + observ_utils.EmitUserAuditsLogs(ctx, " P (K8s Target): Start to create namespace - %s", namespace) _, err = i.Client.CoreV1().Namespaces().Create(ctx, &apiv1.Namespace{ ObjectMeta: metav1.ObjectMeta{ Name: namespace, @@ -540,7 +541,7 @@ func (i *K8sTargetProvider) upsertDeployment(ctx context.Context, namespace stri var err error = nil defer observ_utils.CloseSpanWithError(span, &err) defer observ_utils.EmitUserDiagnosticsLogs(ctx, &err) - log.InfofCtx(ctx, " P (K8s Target Provider): upsertDeployment namespace - %s, name - %s", namespace, name) + log.InfofCtx(ctx, " P (K8s Target): upsertDeployment namespace - %s, name - %s", namespace, name) if namespace == "" { namespace = "default" @@ -551,11 +552,11 @@ func (i *K8sTargetProvider) upsertDeployment(ctx context.Context, namespace stri return err } if k8s_errors.IsNotFound(err) { - observ_utils.EmitUserAuditsLogs(ctx, " P (K8s Target Provider): Starting create deployment under namespace - %s, name - %s", namespace, name) + observ_utils.EmitUserAuditsLogs(ctx, " P (K8s Target): Starting create deployment under namespace - %s, name - %s", namespace, name) _, err = i.Client.AppsV1().Deployments(namespace).Create(ctx, deployment, metav1.CreateOptions{}) } else { deployment.ResourceVersion = existing.ResourceVersion - observ_utils.EmitUserAuditsLogs(ctx, " P (K8s Target Provider): Starting update deployment under namespace - %s, name - %s", namespace, name) + observ_utils.EmitUserAuditsLogs(ctx, " P (K8s Target): Starting update deployment under namespace - %s, name - %s", namespace, name) _, err = i.Client.AppsV1().Deployments(namespace).Update(ctx, deployment, metav1.UpdateOptions{}) } if err != nil { @@ -570,7 +571,7 @@ func (i *K8sTargetProvider) upsertService(ctx context.Context, namespace string, var err error = nil defer observ_utils.CloseSpanWithError(span, &err) defer observ_utils.EmitUserDiagnosticsLogs(ctx, &err) - log.InfofCtx(ctx, " P (K8s Target Provider): upsertService namespace - %s, name - %s", namespace, name) + log.InfofCtx(ctx, " P (K8s Target): upsertService namespace - %s, name - %s", namespace, name) if namespace == "" { namespace = "default" @@ -581,11 +582,11 @@ func (i *K8sTargetProvider) upsertService(ctx context.Context, namespace string, return err } if k8s_errors.IsNotFound(err) { - observ_utils.EmitUserAuditsLogs(ctx, " P (K8s Target Provider): Starting create service under namespace - %s, name - %s", namespace, name) + observ_utils.EmitUserAuditsLogs(ctx, " P (K8s Target): Starting create service under namespace - %s, name - %s", namespace, name) _, err = i.Client.CoreV1().Services(namespace).Create(ctx, service, metav1.CreateOptions{}) } else { service.ResourceVersion = existing.ResourceVersion - observ_utils.EmitUserAuditsLogs(ctx, " P (K8s Target Provider): Starting update service under namespace - %s, name - %s", namespace, name) + observ_utils.EmitUserAuditsLogs(ctx, " P (K8s Target): Starting update service under namespace - %s, name - %s", namespace, name) _, err = i.Client.CoreV1().Services(namespace).Update(ctx, service, metav1.UpdateOptions{}) } if err != nil { @@ -595,7 +596,7 @@ func (i *K8sTargetProvider) upsertService(ctx context.Context, namespace string, } func (i *K8sTargetProvider) deployComponents(ctx context.Context, namespace string, name string, metadata map[string]string, components []model.ComponentSpec, projector IK8sProjector, instanceName string) error { var err error = nil - log.InfofCtx(ctx, " P (K8s Target Provider): deployComponents namespace - %s, name - %s", namespace, name) + log.InfofCtx(ctx, " P (K8s Target): deployComponents namespace - %s, name - %s", namespace, name) if namespace == "" { namespace = "default" @@ -605,46 +606,46 @@ func (i *K8sTargetProvider) deployComponents(ctx context.Context, namespace stri if projector != nil { err = projector.ProjectDeployment(namespace, name, metadata, components, deployment) if err != nil { - log.DebugfCtx(ctx, " P (K8s Target Provider): failed to project deployment: %s", err.Error()) + log.DebugfCtx(ctx, " P (K8s Target): failed to project deployment: %s", err.Error()) return err } } if err != nil { - log.DebugfCtx(ctx, " P (K8s Target Provider): failed to apply: %s", err.Error()) + log.DebugfCtx(ctx, " P (K8s Target): failed to apply: %s", err.Error()) return err } service, err := metadataToService(ctx, namespace, name, metadata) if err != nil { - log.DebugfCtx(ctx, " P (K8s Target Provider): failed to apply (convert): %s", err.Error()) + log.DebugfCtx(ctx, " P (K8s Target): failed to apply (convert): %s", err.Error()) return err } if projector != nil { err = projector.ProjectService(namespace, name, metadata, service) if err != nil { - log.DebugfCtx(ctx, " P (K8s Target Provider): failed to project service: %s", err.Error()) + log.DebugfCtx(ctx, " P (K8s Target): failed to project service: %s", err.Error()) return err } } - log.DebugCtx(ctx, " P (K8s Target Provider): checking namespace") + log.DebugCtx(ctx, " P (K8s Target): checking namespace") err = i.createNamespace(ctx, namespace) if err != nil { - log.DebugfCtx(ctx, " P (K8s Target Provider): failed to create namespace: %s", err.Error()) + log.DebugfCtx(ctx, " P (K8s Target): failed to create namespace: %s", err.Error()) return err } - log.DebugCtx(ctx, " P (K8s Target Provider): creating deployment") + log.DebugCtx(ctx, " P (K8s Target): creating deployment") err = i.upsertDeployment(ctx, namespace, name, deployment) if err != nil { - log.DebugfCtx(ctx, " P (K8s Target Provider): failed to apply (API): %s", err.Error()) + log.DebugfCtx(ctx, " P (K8s Target): failed to apply (API): %s", err.Error()) return err } if service != nil { - log.DebugCtx(ctx, " P (K8s Target Provider): creating service") + log.DebugCtx(ctx, " P (K8s Target): creating service") err = i.upsertService(ctx, namespace, service.Name, service) if err != nil { - log.DebugfCtx(ctx, " P (K8s Target Provider): failed to apply (service): %s", err.Error()) + log.DebugfCtx(ctx, " P (K8s Target): failed to apply (service): %s", err.Error()) return err } } @@ -682,14 +683,14 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, defer observ_utils.CloseSpanWithError(span, &err) defer observ_utils.EmitUserDiagnosticsLogs(ctx, &err) - log.InfofCtx(ctx, " P (K8s Target Provider): applying artifacts: %s - %s", dep.Instance.Spec.Scope, dep.Instance.ObjectMeta.Name) + log.InfofCtx(ctx, " P (K8s Target): applying artifacts: %s - %s", dep.Instance.Spec.Scope, dep.Instance.ObjectMeta.Name) functionName := observ_utils.GetFunctionName() applyTime := time.Now().UTC() components := step.GetComponents() err = i.GetValidationRule(ctx).Validate(components) if err != nil { - log.ErrorfCtx(ctx, " P (K8s Target Provider): failed to validate components, error: %v", err) + log.ErrorfCtx(ctx, " P (K8s Target): failed to validate components, error: %v", err) err = v1alpha2.NewCOAError(err, fmt.Sprintf("%s: the rule validation failed", componentName), v1alpha2.ValidateFailed) providerOperationMetrics.ProviderOperationErrors( k8s, @@ -701,6 +702,7 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, return nil, err } if isDryRun { + log.DebugfCtx(ctx, " P (K8s Target): dryRun is enabled,, skipping apply") return nil, nil } @@ -708,7 +710,7 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, projector, err := createProjector(i.Config.Projector) if err != nil { - log.DebugfCtx(ctx, " P (K8s Target Provider): failed to create projector: %s", err.Error()) + log.DebugfCtx(ctx, " P (K8s Target): failed to create projector: %s", err.Error()) err = v1alpha2.NewCOAError(err, fmt.Sprintf("%s: failed to create projector", componentName), v1alpha2.CreateProjectorFailed) providerOperationMetrics.ProviderOperationErrors( k8s, @@ -726,7 +728,7 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, if len(updated) > 0 { err = i.deployComponents(ctx, dep.Instance.Spec.Scope, dep.Instance.ObjectMeta.Name, dep.Instance.Spec.Metadata, components, projector, dep.Instance.ObjectMeta.Name) if err != nil { - log.DebugfCtx(ctx, " P (K8s Target Provider): failed to apply components: %s", err.Error()) + log.DebugfCtx(ctx, " P (K8s Target): failed to apply components: %s", err.Error()) err = v1alpha2.NewCOAError(err, fmt.Sprintf("%s: failed to deploy components", componentName), v1alpha2.K8sDeploymentFailed) providerOperationMetrics.ProviderOperationErrors( k8s, @@ -754,7 +756,7 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, } err = i.removeService(ctx, dep.Instance.Spec.Scope, serviceName) if err != nil { - log.DebugfCtx(ctx, " P (K8s Target Provider): failed to remove service: %s", err.Error()) + log.DebugfCtx(ctx, " P (K8s Target): failed to remove service: %s", err.Error()) err = v1alpha2.NewCOAError(err, fmt.Sprintf("%s: failed to remove k8s service", componentName), v1alpha2.K8sRemoveServiceFailed) providerOperationMetrics.ProviderOperationErrors( k8s, @@ -767,7 +769,7 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, } err = i.removeDeployment(ctx, dep.Instance.Spec.Scope, dep.Instance.ObjectMeta.Name) if err != nil { - log.DebugfCtx(ctx, " P (K8s Target Provider): failed to remove deployment: %s", err.Error()) + log.DebugfCtx(ctx, " P (K8s Target): failed to remove deployment: %s", err.Error()) err = v1alpha2.NewCOAError(err, fmt.Sprintf("%s: failed to remove k8s deployment", componentName), v1alpha2.K8sRemoveDeploymentFailed) providerOperationMetrics.ProviderOperationErrors( k8s, @@ -781,7 +783,7 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, if i.Config.DeleteEmptyNamespace { err = i.removeNamespace(ctx, dep.Instance.Spec.Scope, i.Config.RetryCount, i.Config.RetryIntervalInSec) if err != nil { - log.DebugfCtx(ctx, " P (K8s Target Provider): failed to remove namespace: %s", err.Error()) + log.DebugfCtx(ctx, " P (K8s Target): failed to remove namespace: %s", err.Error()) } } providerOperationMetrics.ProviderOperationLatency( @@ -810,7 +812,7 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, } err = i.deployComponents(ctx, scope, component.Name, component.Metadata, []model.ComponentSpec{component}, projector, dep.Instance.ObjectMeta.Name) if err != nil { - log.DebugfCtx(ctx, " P (K8s Target Provider): failed to apply components: %s", err.Error()) + log.DebugfCtx(ctx, " P (K8s Target): failed to apply components: %s", err.Error()) err = v1alpha2.NewCOAError(err, fmt.Sprintf("%s: failed to deploy components", componentName), v1alpha2.K8sDeploymentFailed) providerOperationMetrics.ProviderOperationErrors( k8s, @@ -850,7 +852,7 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, Status: v1alpha2.DeleteFailed, Message: err.Error(), } - log.DebugfCtx(ctx, "P (K8s Target Provider): failed to remove service: %s", err.Error()) + log.DebugfCtx(ctx, "P (K8s Target): failed to remove service: %s", err.Error()) err = v1alpha2.NewCOAError(err, fmt.Sprintf("%s: failed to remove k8s service", componentName), v1alpha2.K8sRemoveServiceFailed) providerOperationMetrics.ProviderOperationErrors( k8s, @@ -867,7 +869,7 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, Status: v1alpha2.DeleteFailed, Message: err.Error(), } - log.DebugfCtx(ctx, "P (K8s Target Provider): failed to remove deployment: %s", err.Error()) + log.DebugfCtx(ctx, "P (K8s Target): failed to remove deployment: %s", err.Error()) err = v1alpha2.NewCOAError(err, fmt.Sprintf("%s: failed to remove k8s deployment", componentName), v1alpha2.K8sRemoveDeploymentFailed) providerOperationMetrics.ProviderOperationErrors( k8s, @@ -881,7 +883,7 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, if i.Config.DeleteEmptyNamespace { err = i.removeNamespace(ctx, dep.Instance.Spec.Scope, i.Config.RetryCount, i.Config.RetryIntervalInSec) if err != nil { - log.DebugfCtx(ctx, "P (K8s Target Provider): failed to remove namespace: %s", err.Error()) + log.DebugfCtx(ctx, "P (K8s Target): failed to remove namespace: %s", err.Error()) } } } @@ -922,7 +924,7 @@ func deploymentToComponents(ctx context.Context, deployment v1.Deployment) ([]mo } } componentsJson, _ := json.Marshal(components) - log.DebugfCtx(ctx, " P (K8s Target Provider): deploymentToComponents - components: %s", string(componentsJson)) + log.DebugfCtx(ctx, " P (K8s Target): deploymentToComponents - components: %s", string(componentsJson)) return components, nil } func convertComponentSpecToSidecar(c model.ComponentSpec) model.SidecarSpec { @@ -982,10 +984,10 @@ func metadataToService(ctx context.Context, namespace string, name string, metad servicePorts := make([]apiv1.ServicePort, 0) if v, ok := metadata["service.ports"]; ok && v != "" { - log.DebugfCtx(ctx, " P (K8s Target Provider): metadataToService - service ports: %s", v) + log.DebugfCtx(ctx, " P (K8s Target): metadataToService - service ports: %s", v) e := json.Unmarshal([]byte(v), &servicePorts) if e != nil { - log.ErrorfCtx(ctx, " P (K8s Target Provider): metadataToService - unmarshal: %v", e) + log.ErrorfCtx(ctx, " P (K8s Target): metadataToService - unmarshal: %v", e) return nil, e } } else { diff --git a/api/pkg/apis/v1alpha1/providers/target/kubectl/kubectl.go b/api/pkg/apis/v1alpha1/providers/target/kubectl/kubectl.go index dfa27cd32..d24c34097 100644 --- a/api/pkg/apis/v1alpha1/providers/target/kubectl/kubectl.go +++ b/api/pkg/apis/v1alpha1/providers/target/kubectl/kubectl.go @@ -132,6 +132,7 @@ func KubectlTargetProviderConfigFromMap(properties map[string]string) (KubectlTa func (i *KubectlTargetProvider) InitWithMap(properties map[string]string) error { config, err := KubectlTargetProviderConfigFromMap(properties) if err != nil { + sLog.Errorf(" P (Kubectl Target): expected KubectlTargetProviderConfig: %+v", err) return v1alpha2.NewCOAError(err, fmt.Sprintf("%s: failed to init", providerName), v1alpha2.InitFailed) } @@ -304,6 +305,7 @@ func (i *KubectlTargetProvider) Get(ctx context.Context, deployment model.Deploy return nil, err } + sLog.InfofCtx(ctx, " P (Kubectl Target): append component: %s", component.Component.Name) ret = append(ret, component.Component) stop = true //we do early stop as soon as we found the first resource. we may want to support different strategy in the future @@ -342,9 +344,8 @@ func (i *KubectlTargetProvider) Get(ctx context.Context, deployment model.Deploy err = v1alpha2.NewCOAError(err, fmt.Sprintf("%s: failed to get custom resource from data bytes in component resource property", providerName), v1alpha2.GetComponentSpecFailed) return nil, err } - + sLog.InfofCtx(ctx, " P (Kubectl Target): append component: %s", component.Component.Name) ret = append(ret, component.Component) - } else { err = v1alpha2.NewCOAError(nil, fmt.Sprintf("%s: component doesn't have yaml or resource property", providerName), v1alpha2.GetComponentSpecFailed) sLog.ErrorCtx(ctx, " P (Kubectl Target): component doesn't have yaml or resource property") @@ -387,12 +388,14 @@ func (i *KubectlTargetProvider) Apply(ctx context.Context, deployment model.Depl return nil, err } if isDryRun { + sLog.DebugfCtx(ctx, " P (Kubectl Target): dryRun is enabled,, skipping apply") return nil, nil } ret := step.PrepareResultMap() components = step.GetUpdatedComponents() if len(components) > 0 { + sLog.InfofCtx(ctx, " P (Kubectl Target): get updated components: count - %d", len(components)) for _, component := range components { applyComponentTime := time.Now().UTC() if component.Type == "yaml.k8s" { @@ -584,6 +587,7 @@ func (i *KubectlTargetProvider) Apply(ctx context.Context, deployment model.Depl deleteTime := time.Now().UTC() components = step.GetDeletedComponents() if len(components) > 0 { + sLog.InfofCtx(ctx, " P (Kubectl Target): get deleted components: count - %d", len(components)) for _, component := range components { deleteComponentTime := time.Now().UTC() if component.Type == "yaml.k8s" { @@ -1049,6 +1053,7 @@ func (i *KubectlTargetProvider) deleteCustomResource(ctx context.Context, dataBy // applyCustomResource applies a custom resource from a byte array func (i *KubectlTargetProvider) applyCustomResource(ctx context.Context, dataBytes []byte, namespace string, instance model.InstanceState) error { + sLog.ErrorfCtx(ctx, " P (Kubectl Target): apply custom resource in the namespace: %s", namespace) obj, dr, err := i.buildDynamicResourceClient(dataBytes, namespace) if err != nil { sLog.ErrorfCtx(ctx, " P (Kubectl Target): failed to build a new dynamic client: %+v", err) @@ -1061,6 +1066,8 @@ func (i *KubectlTargetProvider) applyCustomResource(ctx context.Context, dataByt if !kerrors.IsNotFound(err) { sLog.ErrorfCtx(ctx, " P (Kubectl Target): failed to read object: %+v", err) return err + } else { + sLog.InfofCtx(ctx, " P (Kubectl Target): object %s not found: %+v", obj.GetName(), err) } if err = i.MetaPopulator.PopulateMeta(obj, instance); err != nil { diff --git a/api/pkg/apis/v1alpha1/providers/target/mqtt/mqtt.go b/api/pkg/apis/v1alpha1/providers/target/mqtt/mqtt.go index aabba237a..ff199eae5 100644 --- a/api/pkg/apis/v1alpha1/providers/target/mqtt/mqtt.go +++ b/api/pkg/apis/v1alpha1/providers/target/mqtt/mqtt.go @@ -131,6 +131,7 @@ func MQTTTargetProviderConfigFromMap(properties map[string]string) (MQTTTargetPr func (i *MQTTTargetProvider) InitWithMap(properties map[string]string) error { config, err := MQTTTargetProviderConfigFromMap(properties) if err != nil { + sLog.Errorf(" P (MQTT Target): expected MQTTTargetProviderConfig: %+v", err) return err } return i.Init(config) @@ -158,7 +159,7 @@ func (i *MQTTTargetProvider) Init(config providers.IProviderConfig) error { } updateConfig, err := toMQTTTargetProviderConfig(config) if err != nil { - sLog.ErrorfCtx(ctx, " P (MQTT Target): expected HttpTargetProviderConfig: %+v", err) + sLog.ErrorfCtx(ctx, " P (MQTT Target): expected MQTTTargetProviderConfig: %+v", err) return err } i.Config = updateConfig @@ -274,6 +275,7 @@ func (i *MQTTTargetProvider) Get(ctx context.Context, deployment model.Deploymen } data, _ = json.Marshal(request) + sLog.InfofCtx(ctx, " P (MQTT Target): start to publish on topic %s", i.Config.RequestTopic) if token := i.MQTTClient.Publish(i.Config.RequestTopic, 0, false, data); token.Wait() && token.Error() != nil { sLog.ErrorfCtx(ctx, " P (MQTT Target): failed to getting artifacts - %s", token.Error()) err = token.Error() @@ -333,8 +335,10 @@ func (i *MQTTTargetProvider) Remove(ctx context.Context, deployment model.Deploy } data, _ = json.Marshal(request) + sLog.InfofCtx(ctx, " P (MQTT Target): start to publish on topic %s", i.Config.RequestTopic) if token := i.MQTTClient.Publish(i.Config.RequestTopic, 0, false, data); token.Wait() && token.Error() != nil { err = token.Error() + sLog.ErrorfCtx(ctx, " P (MQTT Target): failed to publish - %v", err) return err } @@ -381,7 +385,7 @@ func (i *MQTTTargetProvider) Apply(ctx context.Context, deployment model.Deploym return nil, err } if isDryRun { - err = nil + sLog.DebugCtx(ctx, " P (MQTT Target): dryRun is enabled, skipping apply") return nil, nil } @@ -390,7 +394,7 @@ func (i *MQTTTargetProvider) Apply(ctx context.Context, deployment model.Deploym components = step.GetUpdatedComponents() if len(components) > 0 { - + sLog.InfofCtx(ctx, " P (MQTT Target): get updated components: count - %d", len(components)) ctx = coalogcontexts.GenerateCorrelationIdToParentContextIfMissing(ctx) request := v1alpha2.COARequest{ Route: "instances", @@ -405,6 +409,7 @@ func (i *MQTTTargetProvider) Apply(ctx context.Context, deployment model.Deploym data, _ = json.Marshal(request) utils.EmitUserAuditsLogs(ctx, " P (MQTT Target): Start to send Apply()-Update request over MQTT on topic %s", i.Config.RequestTopic) + sLog.InfofCtx(ctx, " P (MQTT Target): start to publish on topic %s", i.Config.RequestTopic) if token := i.MQTTClient.Publish(i.Config.RequestTopic, 0, false, data); token.Wait() && token.Error() != nil { err = token.Error() providerOperationMetrics.ProviderOperationErrors( @@ -467,6 +472,7 @@ func (i *MQTTTargetProvider) Apply(ctx context.Context, deployment model.Deploym deleteTime := time.Now().UTC() components = step.GetDeletedComponents() if len(components) > 0 { + sLog.InfofCtx(ctx, " P (MQTT Target): get deleted components: count - %d", len(components)) ctx = coalogcontexts.GenerateCorrelationIdToParentContextIfMissing(ctx) request := v1alpha2.COARequest{ Route: "instances", diff --git a/api/pkg/apis/v1alpha1/providers/target/proxy/proxy.go b/api/pkg/apis/v1alpha1/providers/target/proxy/proxy.go index e6da9660d..1161954f8 100644 --- a/api/pkg/apis/v1alpha1/providers/target/proxy/proxy.go +++ b/api/pkg/apis/v1alpha1/providers/target/proxy/proxy.go @@ -55,6 +55,7 @@ func ProxyUpdateProviderConfigFromMap(properties map[string]string) (ProxyUpdate func (i *ProxyUpdateProvider) InitWithMap(properties map[string]string) error { config, err := ProxyUpdateProviderConfigFromMap(properties) if err != nil { + sLog.Errorf(" P (Proxy Target): expected ProxyUpdateProviderConfig: %+v", err) return err } return i.Init(config) @@ -161,6 +162,7 @@ func (i *ProxyUpdateProvider) Apply(ctx context.Context, deployment model.Deploy return nil, err } if isDryRun { + sLog.DebugfCtx(ctx, " P (Proxy Target): dryRun is enabled, skipping apply") err = nil return nil, nil } @@ -168,6 +170,7 @@ func (i *ProxyUpdateProvider) Apply(ctx context.Context, deployment model.Deploy ret := step.PrepareResultMap() components = step.GetUpdatedComponents() if len(components) > 0 { + sLog.InfofCtx(ctx, " P (Proxy Target): get updated components: count - %d", len(components)) data, _ := json.Marshal(deployment) payload, err := i.callRestAPI("instances", "POST", data) @@ -186,11 +189,14 @@ func (i *ProxyUpdateProvider) Apply(ctx context.Context, deployment model.Deploy ret[target] = componentResults } } + } else { + sLog.ErrorfCtx(ctx, " P (Proxy Target): failed to unmarshall post response: %+v", err) } } components = step.GetDeletedComponents() if len(components) > 0 { + sLog.InfofCtx(ctx, " P (Proxy Target): get deleted components: count - %d", len(components)) data, _ := json.Marshal(deployment) _, err = i.callRestAPI("instances", "DELETE", data) if err != nil { diff --git a/api/pkg/apis/v1alpha1/providers/target/script/script.go b/api/pkg/apis/v1alpha1/providers/target/script/script.go index 18b600860..35073c2d7 100644 --- a/api/pkg/apis/v1alpha1/providers/target/script/script.go +++ b/api/pkg/apis/v1alpha1/providers/target/script/script.go @@ -97,6 +97,7 @@ func ScriptProviderConfigFromMap(properties map[string]string) (ScriptProviderCo func (i *ScriptProvider) InitWithMap(properties map[string]string) error { config, err := ScriptProviderConfigFromMap(properties) if err != nil { + sLog.Errorf(" P (Script Target): expected ScriptProviderConfig: %+v", err) return err } return i.Init(config) @@ -336,6 +337,7 @@ func (i *ScriptProvider) Apply(ctx context.Context, deployment model.DeploymentS return nil, err } if isDryRun { + sLog.InfofCtx(ctx, " P (Proxy Target): dryRun is enabled, skipping apply") err = nil return nil, nil } @@ -344,6 +346,7 @@ func (i *ScriptProvider) Apply(ctx context.Context, deployment model.DeploymentS ret := step.PrepareResultMap() components := step.GetUpdatedComponents() if len(components) > 0 { + sLog.InfofCtx(ctx, " P (Script Target): get updated components: count - %d", len(components)) var retU map[string]model.ComponentResultSpec retU, err = i.runScriptOnComponents(ctx, deployment, components, false) if err != nil { @@ -372,6 +375,7 @@ func (i *ScriptProvider) Apply(ctx context.Context, deployment model.DeploymentS deleteTime := time.Now().UTC() components = step.GetDeletedComponents() if len(components) > 0 { + sLog.InfofCtx(ctx, " P (Script Target): get deleted components: count - %d", len(components)) var retU map[string]model.ComponentResultSpec retU, err = i.runScriptOnComponents(ctx, deployment, components, true) if err != nil { diff --git a/api/pkg/apis/v1alpha1/providers/target/staging/staging.go b/api/pkg/apis/v1alpha1/providers/target/staging/staging.go index b8788346a..39d8581f9 100644 --- a/api/pkg/apis/v1alpha1/providers/target/staging/staging.go +++ b/api/pkg/apis/v1alpha1/providers/target/staging/staging.go @@ -53,6 +53,7 @@ func StagingProviderConfigFromMap(properties map[string]string) (StagingTargetPr func (i *StagingTargetProvider) InitWithMap(properties map[string]string) error { config, err := StagingProviderConfigFromMap(properties) if err != nil { + sLog.Errorf(" P (Staging Target): expected StagingTargetProviderConfig: %+v", err) return err } return i.Init(config) @@ -164,7 +165,7 @@ func (i *StagingTargetProvider) Apply(ctx context.Context, deployment model.Depl return nil, err } if isDryRun { - sLog.InfofCtx(ctx, " P (Staging Target): dry run, skipping apply") + sLog.DebugfCtx(ctx, " P (Staging Target): dryRun is enabled, skipping apply") return nil, nil } ret := step.PrepareResultMap() @@ -231,6 +232,7 @@ func (i *StagingTargetProvider) Apply(ctx context.Context, deployment model.Depl components := step.GetUpdatedComponents() if len(components) > 0 { + sLog.InfofCtx(ctx, " P (Staging Target): get updated components: count - %d", len(components)) for i, component := range components { found := false for j, c := range existing { @@ -257,6 +259,7 @@ func (i *StagingTargetProvider) Apply(ctx context.Context, deployment model.Depl components = step.GetDeletedComponents() if len(components) > 0 { + sLog.InfofCtx(ctx, " P (Staging Target): get deleted components: count - %d", len(components)) for i, component := range components { found := false for j, c := range deleted { @@ -286,16 +289,16 @@ func (i *StagingTargetProvider) Apply(ctx context.Context, deployment model.Depl _, err = i.ApiClient.GetCatalogContainer(ctx, containerName, scope, i.Context.SiteInfo.CurrentSite.Username, i.Context.SiteInfo.CurrentSite.Password) if err != nil && strings.Contains(err.Error(), v1alpha2.NotFound.String()) { - sLog.Debugf("Catalog container %s doesn't exist: %s", containerName, err.Error()) + sLog.DebugfCtx(ctx, "Catalog container %s doesn't exist: %s", containerName, err.Error()) catalogContainerState := model.CatalogContainerState{ObjectMeta: model.ObjectMeta{Name: containerName, Namespace: catalog.ObjectMeta.Namespace, Labels: catalog.ObjectMeta.Labels}} containerObjectData, _ := json.Marshal(catalogContainerState) err = i.ApiClient.CreateCatalogContainer(ctx, containerName, containerObjectData, catalog.ObjectMeta.Namespace, i.Context.SiteInfo.CurrentSite.Username, i.Context.SiteInfo.CurrentSite.Password) if err != nil { - sLog.Errorf("Failed to create catalog container %s: %s", containerName, err.Error()) + sLog.ErrorfCtx(ctx, "Failed to create catalog container %s: %s", containerName, err.Error()) return ret, err } } else if err != nil { - sLog.Errorf("Failed to get catalog container %s: %s", containerName, err.Error()) + sLog.ErrorfCtx(ctx, "Failed to get catalog container %s: %s", containerName, err.Error()) return ret, err } diff --git a/api/pkg/apis/v1alpha1/providers/target/win10/sideload/sideload.go b/api/pkg/apis/v1alpha1/providers/target/win10/sideload/sideload.go index 8cabf2930..054e5c5d8 100644 --- a/api/pkg/apis/v1alpha1/providers/target/win10/sideload/sideload.go +++ b/api/pkg/apis/v1alpha1/providers/target/win10/sideload/sideload.go @@ -78,6 +78,7 @@ func Win10SideLoadProviderConfigFromMap(properties map[string]string) (Win10Side func (i *Win10SideLoadProvider) InitWithMap(properties map[string]string) error { config, err := Win10SideLoadProviderConfigFromMap(properties) if err != nil { + sLog.Errorf(" P (Win10Sideload Target): expected Win10SideLoadProviderConfig: %+v", err) return err } return i.Init(config) @@ -215,13 +216,14 @@ func (i *Win10SideLoadProvider) Apply(ctx context.Context, deployment model.Depl return nil, err } if isDryRun { - err = nil + sLog.DebugfCtx(ctx, " P (Win10Sideload Target): dryRun is enabled, skipping apply") return nil, nil } ret := step.PrepareResultMap() components = step.GetUpdatedComponents() if len(components) > 0 { + sLog.InfofCtx(ctx, " P (Win10Sideload Target): get updated components: count - %d", len(components)) for _, component := range components { if path, ok := component.Properties["app.package.path"].(string); ok { params := make([]string, 0) @@ -254,7 +256,7 @@ func (i *Win10SideLoadProvider) Apply(ctx context.Context, deployment model.Depl } components = step.GetDeletedComponents() if len(components) > 0 { - + sLog.InfofCtx(ctx, " P (Win10Sideload Target): get deleted components: count - %d", len(components)) for _, component := range components { if component.Name != "" { params := make([]string, 0) @@ -279,7 +281,7 @@ func (i *Win10SideLoadProvider) Apply(ctx context.Context, deployment model.Depl cmd := exec.Command(i.Config.WinAppDeployCmdPath, params...) err = cmd.Run() if err != nil { - sLog.ErrorfCtx(ctx, " P (Win10Sideload Target): failed to uninstall application %s, error: %+v", name, err) + sLog.ErrorfCtx(ctx, " P (Win10Sideload Target): failed to uninstall application %s, silent config: %t, error: %+v", name, i.Config.Silent, err) if i.Config.Silent { return ret, nil } else {