diff --git a/.github/workflows/go.yml b/.github/workflows/go.yml index 4aaf4a518..3c37f8c36 100644 --- a/.github/workflows/go.yml +++ b/.github/workflows/go.yml @@ -16,6 +16,7 @@ jobs: env: TEST_KUBECTL: yes TEST_MINIKUBE_ENABLED: yes + TEST_MQTT_LOCAL_ENABLED: yes steps: - uses: actions/checkout@v3 @@ -49,6 +50,13 @@ jobs: sudo mv minikube /usr/local/bin/ minikube start kubectl config view + + - name: Install Mqtt + run: | + sudo apt-get update + sudo apt-get install mosquitto mosquitto-clients + sudo service mosquitto start + sudo service mosquitto status - name: COA Test run: cd coa && go test -v ./... -run '^[^C]*$|^[^c][^o]*$|^[^c][^o]*o[^n][^f][^o][^r][^m][^a][^n][^c][^e][^C]*$' diff --git a/api/pkg/apis/v1alpha1/managers/devices/devices-manager.go b/api/pkg/apis/v1alpha1/managers/devices/devices-manager.go index b1d97f27b..6c3f1a3d5 100644 --- a/api/pkg/apis/v1alpha1/managers/devices/devices-manager.go +++ b/api/pkg/apis/v1alpha1/managers/devices/devices-manager.go @@ -16,11 +16,14 @@ import ( "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/managers" "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/providers" "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/providers/states" + "github.com/eclipse-symphony/symphony/coa/pkg/logger" observability "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/observability" observ_utils "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/observability/utils" ) +var log = logger.NewLogger("coa.runtime") + type DevicesManager struct { managers.Manager StateProvider states.IStateProvider @@ -29,10 +32,12 @@ type DevicesManager struct { func (s *DevicesManager) Init(context *contexts.VendorContext, config managers.ManagerConfig, providers map[string]providers.IProvider) error { err := s.Manager.Init(context, config, providers) if err != nil { + log.Errorf("M (Devices): failed to initialize manager %+v", err) return err } stateprovider, err := managers.GetStateProvider(config, providers) if err == nil { + log.Errorf("M (Devices): failed to get state provider %+v", err) s.StateProvider = stateprovider } else { return err @@ -46,6 +51,7 @@ func (t *DevicesManager) DeleteSpec(ctx context.Context, name string) error { }) var err error = nil defer observ_utils.CloseSpanWithError(span, &err) + log.Infof("M (Devices): DeleteSpec name %s, traceId: %s", name, span.SpanContext().TraceID().String()) err = t.StateProvider.Delete(ctx, states.DeleteRequest{ ID: name, @@ -56,7 +62,11 @@ func (t *DevicesManager) DeleteSpec(ctx context.Context, name string) error { "resource": "devices", }, }) - return err + if err != nil { + log.Errorf("M (Devices):failed to delete state %s, error: %v, traceId: %s", name, err, span.SpanContext().TraceID().String()) + return err + } + return nil } func (t *DevicesManager) UpsertSpec(ctx context.Context, name string, spec model.DeviceSpec) error { @@ -65,6 +75,7 @@ func (t *DevicesManager) UpsertSpec(ctx context.Context, name string, spec model }) var err error = nil defer observ_utils.CloseSpanWithError(span, &err) + log.Infof("M (Devices): UpsertSpec name %s, traceId: %s", name, span.SpanContext().TraceID().String()) upsertRequest := states.UpsertRequest{ Value: states.StateEntry{ @@ -88,6 +99,7 @@ func (t *DevicesManager) UpsertSpec(ctx context.Context, name string, spec model } _, err = t.StateProvider.Upsert(ctx, upsertRequest) if err != nil { + log.Errorf("M (Devices): failed to update state %s, error: %v, traceId: %s", name, err, span.SpanContext().TraceID().String()) return err } return nil @@ -99,6 +111,7 @@ func (t *DevicesManager) ListSpec(ctx context.Context) ([]model.DeviceState, err }) var err error = nil defer observ_utils.CloseSpanWithError(span, &err) + log.Infof("M (Devices): ListSpec, traceId: %s", span.SpanContext().TraceID().String()) listRequest := states.ListRequest{ Metadata: map[string]string{ @@ -109,6 +122,7 @@ func (t *DevicesManager) ListSpec(ctx context.Context) ([]model.DeviceState, err } solutions, _, err := t.StateProvider.List(ctx, listRequest) if err != nil { + log.Errorf("M (Devices): failed to list state, error: %v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } ret := make([]model.DeviceState, 0) @@ -116,6 +130,7 @@ func (t *DevicesManager) ListSpec(ctx context.Context) ([]model.DeviceState, err var rt model.DeviceState rt, err = getDeviceState(t.ID, t.Body) if err != nil { + log.Errorf("M (Devices): ListSpec failed to get device state %s, error: %v, traceId: %s", t.ID, err, span.SpanContext().TraceID().String()) return nil, err } ret = append(ret, rt) @@ -146,6 +161,7 @@ func (t *DevicesManager) GetSpec(ctx context.Context, id string) (model.DeviceSt }) var err error = nil defer observ_utils.CloseSpanWithError(span, &err) + log.Infof("M (Devices): GetSpec id %s, traceId: %s", id, span.SpanContext().TraceID().String()) getRequest := states.GetRequest{ ID: id, @@ -157,11 +173,13 @@ func (t *DevicesManager) GetSpec(ctx context.Context, id string) (model.DeviceSt } target, err := t.StateProvider.Get(ctx, getRequest) if err != nil { + log.Errorf("M (Devices): failed to get state %s, error: %v, traceId: %s", id, err, span.SpanContext().TraceID().String()) return model.DeviceState{}, err } ret, err := getDeviceState(id, target.Body) if err != nil { + log.Errorf("M (Devices): GetSpec failed to get device state, error: %v, traceId: %s", err, span.SpanContext().TraceID().String()) return model.DeviceState{}, err } return ret, nil diff --git a/api/pkg/apis/v1alpha1/managers/reference/reference-manager.go b/api/pkg/apis/v1alpha1/managers/reference/reference-manager.go index 2a7ff8efb..7fb7895d8 100644 --- a/api/pkg/apis/v1alpha1/managers/reference/reference-manager.go +++ b/api/pkg/apis/v1alpha1/managers/reference/reference-manager.go @@ -22,9 +22,12 @@ import ( "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/providers/reference" "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/providers/reporter" "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/providers/states" + "github.com/eclipse-symphony/symphony/coa/pkg/logger" "github.com/oliveagle/jsonpath" ) +var log = logger.NewLogger("coa.runtime") + type ReferenceManager struct { managers.Manager ReferenceProviders map[string]reference.IReferenceProvider @@ -39,9 +42,9 @@ type CachedItem struct { } func (s *ReferenceManager) Init(context *contexts.VendorContext, config managers.ManagerConfig, providers map[string]providers.IProvider) error { - err := s.Manager.Init(context, config, providers) if err != nil { + log.Errorf("M (Reference): failed to initialize manager %+v", err) return err } @@ -49,6 +52,7 @@ func (s *ReferenceManager) Init(context *contexts.VendorContext, config managers if err == nil { s.StateProvider = stateProvider } else { + log.Errorf("M (Reference): failed to get state provider %+v", err) return err } @@ -56,12 +60,14 @@ func (s *ReferenceManager) Init(context *contexts.VendorContext, config managers if err == nil { s.Reporter = reportProvider } else { + log.Errorf("M (Reference): failed to get reporter %+v", err) return err } ctx := contexts.ManagerContext{} err = ctx.Init(context, nil) if err != nil { + log.Errorf("M (Reference): failed to initialize manager context %+v", err) return err } @@ -88,51 +94,63 @@ func (s *ReferenceManager) Init(context *contexts.VendorContext, config managers } func (s *ReferenceManager) GetExt(refType string, namespace string, id1 string, group1 string, kind1 string, version1 string, id2 string, group2 string, kind2 string, version2 string, iteration string, alias string) ([]byte, error) { + log.Infof("M (Reference): GetExt id1 - %s, id2 - %s, group2 - %s", id1, id2, group2) + if group2 != "download" { data1, err := s.Get(refType, id1, namespace, group1, kind1, version1, "", "") if err != nil { + log.Errorf("M (Reference): failed to get %s: %+v", id1, err) return nil, err } data2, err := s.Get(refType, id2, namespace, group2, kind2, version2, "", "") if err != nil { + log.Errorf("M (Reference): failed to get %s: %+v", id2, err) return nil, err } return fillParameters(data1, data2, id1, alias) } else { data1, err := s.Get(refType, id1, namespace, group1, kind1, version1, "", "") if err != nil { + log.Errorf("M (Reference): failed to get %s: %+v", id1, err) return nil, err } obj := make(map[string]interface{}, 0) err = json.Unmarshal(data1, &obj) if err != nil { + log.Errorf("M (Reference): failed to unmarshall %s object: %+v", id1, err) return nil, err } var specData []byte if v, ok := obj["spec"]; ok { specData, err = json.Marshal(v) if err != nil { + log.Errorf("M (Reference): failed to unmarshall %s spec: %+v", id1, err) return nil, err } } else { + log.Errorf("M (Reference): %s spec property not found", id1) return nil, v1alpha2.NewCOAError(nil, "resolved object doesn't contain a 'spec' property", v1alpha2.InternalError) } model := model.ModelSpec{} err = json.Unmarshal(specData, &model) if err != nil { + log.Errorf("M (Reference): failed to unmarshall %s object spec: %+v", id1, err) return nil, err } modelType := safeRead("model.type", model.Properties) if modelType != "customvision" { + log.Errorf("M (Reference): failed to unmarshall %s object spec:", id1) return nil, v1alpha2.NewCOAError(nil, "only 'customvision' model type is supported", v1alpha2.InternalError) } modelProject := safeRead("model.project", model.Properties) if modelProject == "" { + log.Errorf("M (Reference): failed to read %s model.project property", id1) return nil, v1alpha2.NewCOAError(nil, "property 'model.project' is not found", v1alpha2.InternalError) } modelEndpoint := safeRead("model.endpoint", model.Properties) if modelEndpoint == "" { + log.Errorf("M (Reference): failed to read %s model.endpoint property", id1) return nil, v1alpha2.NewCOAError(nil, "property 'model.endpoint' is not found", v1alpha2.InternalError) } modelVersions := make(map[string]string) @@ -142,6 +160,7 @@ func (s *ReferenceManager) GetExt(refType string, namespace string, id1 string, } } if len(modelVersions) == 0 { + log.Errorf("M (Reference): failed to read %s model.version property", id1) return nil, v1alpha2.NewCOAError(nil, "no model version are found", v1alpha2.InternalError) } selection := "" @@ -153,11 +172,13 @@ func (s *ReferenceManager) GetExt(refType string, namespace string, id1 string, } } if selection == "" { + log.Errorf("M (Reference): failed to read %s model.version property", id1) return nil, v1alpha2.NewCOAError(nil, fmt.Sprintf("requested version 'model.version.%s' is not found", iteration), v1alpha2.InternalError) } downloadData, err := s.Get("v1alpha2.CustomVision", modelProject, modelEndpoint, kind2, version2, selection, "", "") if err != nil { + log.Errorf("M (Reference): failed to get %s: %+v", modelProject, err) return nil, err } return downloadData, nil @@ -191,6 +212,9 @@ func (s *ReferenceManager) Get(refType string, id string, namespace string, grou } else { entityId = fmt.Sprintf("%s-%s-%s-%s-%s-%s", refType, id, namespace, group, kind, version) } + + log.Infof("M (Reference): Get entityId- %s", entityId) + entity, err := s.StateProvider.Get(context.TODO(), states.GetRequest{ ID: entityId, }) @@ -239,7 +263,6 @@ func (s *ReferenceManager) Get(refType string, id string, namespace string, grou }) refData, _ := json.Marshal(ref) return refData, nil - } func (s *ReferenceManager) Report(id string, namespace string, group string, kind string, version string, properties map[string]string, overwrite bool) error { diff --git a/api/pkg/apis/v1alpha1/managers/target/target-manager.go b/api/pkg/apis/v1alpha1/managers/target/target-manager.go index e7f4e3ed9..80575c4f2 100644 --- a/api/pkg/apis/v1alpha1/managers/target/target-manager.go +++ b/api/pkg/apis/v1alpha1/managers/target/target-manager.go @@ -51,11 +51,11 @@ type DeviceSpec struct { } func (s *TargetManager) Init(context *contexts.VendorContext, config managers.ManagerConfig, providers map[string]providers.IProvider) error { - probeProvider, err := managers.GetProbeProvider(config, providers) if err == nil { s.ProbeProvider = probeProvider } else { + log.Errorf("M (Target): failed to get probe provider %+v", err) return err } @@ -63,6 +63,7 @@ func (s *TargetManager) Init(context *contexts.VendorContext, config managers.Ma if err == nil { s.ReferenceProvider = referenceProvider } else { + log.Errorf("M (Target): failed to get reference provider %+v", err) return err } @@ -70,6 +71,7 @@ func (s *TargetManager) Init(context *contexts.VendorContext, config managers.Ma if err == nil { s.UploaderProvider = uploaderProvider } else { + log.Errorf("M (Target): failed to get upload provider %+v", err) return err } @@ -77,6 +79,7 @@ func (s *TargetManager) Init(context *contexts.VendorContext, config managers.Ma if err == nil { s.Reporter = reporterProvider } else { + log.Errorf("M (Target): failed to get reporter %+v", err) return err } @@ -97,6 +100,7 @@ func (s *TargetManager) Enabled() bool { } func (s *TargetManager) Poll() []error { target := s.ReferenceProvider.TargetID() + log.Infof("M (Target): Poll target- %s", target) ret, err := s.ReferenceProvider.List(target+"=true", "", "default", model.FabricGroup, "devices", "v1", "v1alpha2.ReferenceK8sCRD") if err != nil { @@ -170,6 +174,8 @@ func (s *TargetManager) Poll() []error { return errors } func (s *TargetManager) reportStatus(deviceName string, targetName string, snapshot string, targetStatus string, deviceStatus string, overwrite bool, errStr string) []error { + log.Infof("M (Target): reportStatus deviceName- %s, targetName - %s, snapshot -%s targetStatus -%s, deviceStatus -%s, overwrite -%s", deviceName, targetName, snapshot, targetStatus, deviceStatus, overwrite) + ret := make([]error, 0) report := make(map[string]string) report[targetName+".status"] = targetStatus @@ -194,6 +200,7 @@ func (s *TargetManager) reportStatus(deviceName string, targetName string, snaps log.Debugf("failed to report target status: %s", err.Error()) ret = append(ret, err) } + return ret } func (s *TargetManager) Reconcil() []error { diff --git a/api/pkg/apis/v1alpha1/managers/users/users-manager.go b/api/pkg/apis/v1alpha1/managers/users/users-manager.go index 69f875df9..65dfaf472 100644 --- a/api/pkg/apis/v1alpha1/managers/users/users-manager.go +++ b/api/pkg/apis/v1alpha1/managers/users/users-manager.go @@ -38,6 +38,7 @@ func (s *UsersManager) Init(context *contexts.VendorContext, config managers.Man if err == nil { s.StateProvider = stateprovider } else { + log.Errorf(" M (Users): failed to get state provider %+v", err) return err } @@ -49,11 +50,16 @@ func (t *UsersManager) DeleteUser(ctx context.Context, name string) error { }) var err error = nil defer observ_utils.CloseSpanWithError(span, &err) + log.Infof(" M (Users): DeleteUser name %s, traceId: %s", name, span.SpanContext().TraceID().String()) err = t.StateProvider.Delete(ctx, states.DeleteRequest{ ID: name, }) - return err + if err != nil { + log.Debugf(" M (Users) : failed to delete user %s, traceId: %s", err, span.SpanContext().TraceID().String()) + return err + } + return nil } func hash(name string, s string) string { @@ -68,8 +74,8 @@ func (t *UsersManager) UpsertUser(ctx context.Context, name string, password str }) var err error = nil defer observ_utils.CloseSpanWithError(span, &err) + log.Infof(" M (Users): UpsertUser name %s, traceId: %s", name, span.SpanContext().TraceID().String()) - log.Debug(" M (Users) : upsert user") upsertRequest := states.UpsertRequest{ Value: states.StateEntry{ ID: name, @@ -82,7 +88,7 @@ func (t *UsersManager) UpsertUser(ctx context.Context, name string, password str } _, err = t.StateProvider.Upsert(ctx, upsertRequest) if err != nil { - log.Debugf(" M (Users) : failed to upsert user - %s", err) + log.Debugf(" M (Users) : failed to upsert user %v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } return nil @@ -93,23 +99,23 @@ func (t *UsersManager) CheckUser(ctx context.Context, name string, password stri }) var err error = nil defer observ_utils.CloseSpanWithError(span, &err) + log.Infof(" M (Users): CheckUser name %s, traceId: %s", name, span.SpanContext().TraceID().String()) - log.Debug(" M (Users) : check user") getRequest := states.GetRequest{ ID: name, } user, err := t.StateProvider.Get(ctx, getRequest) if err != nil { - log.Debugf(" M (Users) : failed to read user - %s", err) + log.Debugf(" M (Users) : failed to get user %s states, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, false } if v, ok := user.Body.(UserState); ok { if hash(name, password) == v.PasswordHash { - log.Debug(" M (Users) : user authenticated") + log.Debugf(" M (Users) : user authenticated, traceId: %s", span.SpanContext().TraceID().String()) return v.Roles, true } } - log.Debug(" M (Users) : authentication failed") + log.Debugf(" M (Users) : authentication failed, traceId: %s", span.SpanContext().TraceID().String()) return nil, false } diff --git a/api/pkg/apis/v1alpha1/providers/states/k8s/k8s.go b/api/pkg/apis/v1alpha1/providers/states/k8s/k8s.go index 1a4d8cbe3..4b68bdf3c 100644 --- a/api/pkg/apis/v1alpha1/providers/states/k8s/k8s.go +++ b/api/pkg/apis/v1alpha1/providers/states/k8s/k8s.go @@ -189,8 +189,12 @@ func (s *K8sStateProvider) Upsert(ctx context.Context, entry states.UpsertReques Resource: resource, } - j, _ := json.Marshal(entry.Value.Body) + if entry.Value.ID == "" { + err := v1alpha2.NewCOAError(nil, "found invalid request ID", v1alpha2.InternalError) + return "", err + } + j, _ := json.Marshal(entry.Value.Body) item, err := s.DynamicClient.Resource(resourceId).Namespace(scope).Get(ctx, entry.Value.ID, metav1.GetOptions{}) if err != nil { // TODO: check if not-found error @@ -355,6 +359,11 @@ func (s *K8sStateProvider) Delete(ctx context.Context, request states.DeleteRequ scope = "default" } + if request.ID == "" { + err := v1alpha2.NewCOAError(nil, "found invalid request ID", v1alpha2.InternalError) + return err + } + err = s.DynamicClient.Resource(resourceId).Namespace(scope).Delete(ctx, request.ID, metav1.DeleteOptions{}) if err != nil { sLog.Errorf(" P (K8s State): failed to delete objects: %v", err) @@ -387,6 +396,11 @@ func (s *K8sStateProvider) Get(ctx context.Context, request states.GetRequest) ( Resource: resource, } + if request.ID == "" { + err := v1alpha2.NewCOAError(nil, "found invalid request ID", v1alpha2.InternalError) + return states.StateEntry{}, err + } + item, err := s.DynamicClient.Resource(resourceId).Namespace(scope).Get(ctx, request.ID, metav1.GetOptions{}) if err != nil { coaError := v1alpha2.NewCOAError(err, "failed to get object", v1alpha2.InternalError) diff --git a/api/pkg/apis/v1alpha1/providers/states/k8s/k8s_test.go b/api/pkg/apis/v1alpha1/providers/states/k8s/k8s_test.go index 11f78db01..6bd945ada 100644 --- a/api/pkg/apis/v1alpha1/providers/states/k8s/k8s_test.go +++ b/api/pkg/apis/v1alpha1/providers/states/k8s/k8s_test.go @@ -72,7 +72,7 @@ func TestInitWithBadData(t *testing.T) { assert.NotNil(t, err) } -func TestUpSert(t *testing.T) { +func TestUpsert(t *testing.T) { testK8s := os.Getenv("TEST_K8S_STATE") if testK8s == "" { t.Skip("Skipping because TEST_K8S_STATE enviornment variable is not set") diff --git a/api/pkg/apis/v1alpha1/providers/target/adb/adb.go b/api/pkg/apis/v1alpha1/providers/target/adb/adb.go index 60b69f340..eb88a3c56 100644 --- a/api/pkg/apis/v1alpha1/providers/target/adb/adb.go +++ b/api/pkg/apis/v1alpha1/providers/target/adb/adb.go @@ -65,6 +65,7 @@ func (i *AdbProvider) Init(config providers.IProviderConfig) error { updateConfig, err := toAdbProviderConfig(config) if err != nil { + aLog.Errorf(" P (Android ADB): expected AdbProviderConfig: %+v", err) return errors.New("expected AdbProviderConfig") } i.Config = updateConfig @@ -88,7 +89,7 @@ func (i *AdbProvider) Get(ctx context.Context, deployment model.DeploymentSpec, var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - aLog.Infof(" P (Android ADB): getting artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + aLog.Infof(" P (Android ADB): getting artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) ret := make([]model.ComponentSpec, 0) @@ -106,6 +107,7 @@ func (i *AdbProvider) Get(ctx context.Context, deployment model.DeploymentSpec, out, err = exec.Command("adb", params...).Output() if err != nil { + aLog.Errorf(" P (Android ADB): failed to get application %+v, error: %+v, traceId: %s", p, err, span.SpanContext().TraceID().String()) return nil, err } str := string(out) @@ -130,12 +132,13 @@ func (i *AdbProvider) Apply(ctx context.Context, deployment model.DeploymentSpec var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - aLog.Infof(" P (Android ADB Provider): applying artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + aLog.Infof(" P (Android ADB Provider): applying artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) components := step.GetComponents() err = i.GetValidationRule(ctx).Validate(components) if err != nil { + aLog.Errorf(" P (Android ADB Provider): failed to validate components, error: %v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } if isDryRun { @@ -155,6 +158,7 @@ func (i *AdbProvider) Apply(ctx context.Context, deployment model.DeploymentSpec cmd := exec.Command("adb", params...) err = cmd.Run() if err != nil { + aLog.Errorf(" P (Android ADB): failed to install application %+v, error: %+v, traceId: %s", p, err, span.SpanContext().TraceID().String()) ret[component.Name] = model.ComponentResultSpec{ Status: v1alpha2.UpdateFailed, Message: err.Error(), @@ -178,6 +182,7 @@ func (i *AdbProvider) Apply(ctx context.Context, deployment model.DeploymentSpec cmd := exec.Command("adb", params...) err = cmd.Run() if err != nil { + aLog.Errorf(" P (Android ADB): failed to uninstall application %+v, error: %+v, traceId: %s", p, err, span.SpanContext().TraceID().String()) 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 679e1645a..606e4456c 100644 --- a/api/pkg/apis/v1alpha1/providers/target/azure/adu/adu.go +++ b/api/pkg/apis/v1alpha1/providers/target/azure/adu/adu.go @@ -81,6 +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 Provider): expected ADUTargetProviderConfig %+v", err) return err } return i.Init(config) @@ -97,11 +98,11 @@ func (i *ADUTargetProvider) Init(config providers.IProviderConfig) error { var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Info("~~~ ADU Target Provider ~~~ : Init()") + sLog.Info(" P (ADU Target Provider): Init()") updateConfig, err := toADUTargetProviderConfig(config) if err != nil { - sLog.Errorf("~~~ ADU Target Provider ~~~ : expected ADUTargetProviderConfig: %+v", err) + sLog.Errorf(" P (ADU Target Provider): expected ADUTargetProviderConfig: %+v", err) return err } i.Config = updateConfig @@ -131,10 +132,10 @@ func (i *ADUTargetProvider) Get(ctx context.Context, dep model.DeploymentSpec, r var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Info("~~~ ADU Update Provider ~~~ : getting components") + sLog.Info("P (ADU Target Provider): getting components: %s - %s, traceId: %s", dep.Instance.Scope, dep.Instance.Name, span.SpanContext().TraceID().String()) deployment, err := i.getDeployment() if err != nil { - sLog.Errorf("~~~ ADU Target Provider ~~~ : %+v", err) + sLog.Errorf("P (ADU Target Provider): %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } @@ -186,11 +187,12 @@ func (i *ADUTargetProvider) Apply(ctx context.Context, deployment model.Deployme var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Info(" P (ADU Update): applying components") + sLog.Info(" P (ADU Update): applying components: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) components := step.GetComponents() err = i.GetValidationRule(ctx).Validate(components) if err != nil { + sLog.Errorf(" P (ADU Update): failed to validate components, error: %v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } if isDryRun { @@ -204,6 +206,7 @@ func (i *ADUTargetProvider) Apply(ctx context.Context, deployment model.Deployme var deployment azureutils.ADUDeployment deployment, err = getDeploymentFromComponent(c.Component) if err != nil { + sLog.Errorf(" P (ADU Update): failed to get deployment from component: %v, traceId: %s", err, span.SpanContext().TraceID().String()) ret[c.Component.Name] = model.ComponentResultSpec{ Status: v1alpha2.ValidateFailed, Message: err.Error(), @@ -218,12 +221,13 @@ func (i *ADUTargetProvider) Apply(ctx context.Context, deployment model.Deployme Status: v1alpha2.UpdateFailed, Message: err.Error(), } - sLog.Errorf(" P (ADU Update): %+v", err) + sLog.Errorf(" P (ADU Update): failed to apply deployment: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } else { err = i.deleteDeploymeent(deployment) if err != nil { + sLog.Debugf(" P (ADU Update): failed to delete deployment: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) ret[c.Component.Name] = model.ComponentResultSpec{ Status: v1alpha2.DeleteFailed, Message: err.Error(), 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 18c56b6e6..86295d088 100644 --- a/api/pkg/apis/v1alpha1/providers/target/azure/iotedge/iotedge.go +++ b/api/pkg/apis/v1alpha1/providers/target/azure/iotedge/iotedge.go @@ -185,17 +185,17 @@ func (i *IoTEdgeTargetProvider) Get(ctx context.Context, deployment model.Deploy var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Info(" P(IoT Edge Target): getting components") + sLog.Info(" P(IoT Edge Target): getting components: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) hubTwin, err := i.getIoTEdgeModuleTwin(ctx, "$edgeHub") if err != nil { - sLog.Error(" P(IoT Edge Target): +%v", err) + sLog.Error(" P(IoT Edge Target): failed to get edgeHub module twin: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } modules, err := i.getIoTEdgeModules(ctx) if err != nil { - sLog.Error(" P(IoT Edge Target): +%v", err) + sLog.Error(" P(IoT Edge Target): failed to get modules: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } components := make([]model.ComponentSpec, 0) @@ -204,13 +204,13 @@ func (i *IoTEdgeTargetProvider) Get(ctx context.Context, deployment model.Deploy var twin ModuleTwin twin, err = i.getIoTEdgeModuleTwin(ctx, k) if err != nil { - sLog.Error(" P(IoT Edge Target): +%v", err) + sLog.Error(" P(IoT Edge Target): failed to get %s module: +%v, traceId: %s", k, err, span.SpanContext().TraceID().String()) return nil, err } var component model.ComponentSpec component, err = toComponent(hubTwin, twin, deployment.Instance.Name, m) if err != nil { - sLog.Error(" P(IoT Edge Target): +%v", err) + sLog.Error(" P(IoT Edge Target):failed to parse %s twin to component +%v, traceId: %s", k, err, span.SpanContext().TraceID().String()) return nil, err } components = append(components, component) @@ -227,7 +227,7 @@ func (i *IoTEdgeTargetProvider) Apply(ctx context.Context, deployment model.Depl var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Info(" P(IoT Edge Target): applying components") + sLog.Infof(" P(IoT Edge Target): applying components, traceId: %s", span.SpanContext().TraceID().String()) components := step.GetComponents() err = i.GetValidationRule(ctx).Validate(components) @@ -243,13 +243,13 @@ func (i *IoTEdgeTargetProvider) Apply(ctx context.Context, deployment model.Depl edgeAgent, err := i.getIoTEdgeModuleTwin(ctx, "$edgeAgent") if err != nil { - sLog.Errorf(" P(IoT Edge Target): +%v", err) + sLog.Errorf(" P(IoT Edge Target): failed to get edgeAgent moduel twin: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } edgeHub, err := i.getIoTEdgeModuleTwin(ctx, "$edgeHub") if err != nil { - sLog.Errorf(" P(IoT Edge Target): +%v", err) + sLog.Errorf(" P(IoT Edge Target): failed to get edgeHub module twin: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } @@ -263,7 +263,7 @@ func (i *IoTEdgeTargetProvider) Apply(ctx context.Context, deployment model.Depl Message: e.Error(), } err = e - sLog.Errorf(" P(IoT Edge Target): +%v", err) + sLog.Errorf(" P(IoT Edge Target): failed to parse %s component to module: +%v, traceId: %s", a.Name, err, span.SpanContext().TraceID().String()) return ret, err } modules[a.Name] = module @@ -271,7 +271,7 @@ func (i *IoTEdgeTargetProvider) Apply(ctx context.Context, deployment model.Depl if len(modules) > 0 { err = i.deployToIoTEdge(ctx, deployment.Instance.Name, deployment.Instance.Metadata, modules, edgeAgent, edgeHub) if err != nil { - sLog.Errorf(" P(IoT Edge Target): +%v", err) + sLog.Errorf(" P(IoT Edge Target): failed to deploy to IoT edge: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } @@ -285,6 +285,7 @@ func (i *IoTEdgeTargetProvider) Apply(ctx context.Context, deployment model.Depl Status: v1alpha2.DeleteFailed, Message: e.Error(), } + sLog.Errorf(" P(IoT Edge Target): failed to parse %s component to module: +%v, traceId: %s", a.Name, err, span.SpanContext().TraceID().String()) return ret, err } modules[a.Name] = module @@ -292,6 +293,7 @@ func (i *IoTEdgeTargetProvider) Apply(ctx context.Context, deployment model.Depl if len(modules) > 0 { err = i.remvoefromIoTEdge(ctx, deployment.Instance.Name, deployment.Instance.Metadata, modules, edgeAgent, edgeHub) if err != nil { + sLog.Errorf(" P(IoT Edge Target): failed to remove from IoT edge: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } diff --git a/api/pkg/apis/v1alpha1/providers/target/configmap/configmap.go b/api/pkg/apis/v1alpha1/providers/target/configmap/configmap.go index 539bf858a..202852fdc 100644 --- a/api/pkg/apis/v1alpha1/providers/target/configmap/configmap.go +++ b/api/pkg/apis/v1alpha1/providers/target/configmap/configmap.go @@ -97,6 +97,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) return err } @@ -134,7 +135,7 @@ func (i *ConfigMapTargetProvider) Init(config providers.IProviderConfig) error { i.Config.ConfigData = filepath.Join(home, ".kube", "config") } else { err = v1alpha2.NewCOAError(nil, "can't locate home direction to read default kubernetes config file, to run in cluster, set inCluster config setting to true", v1alpha2.BadConfig) - sLog.Errorf(" P (ConfigMap Target): %+v", err) + sLog.Errorf(" P (ConfigMap Target): %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } } @@ -143,40 +144,40 @@ func (i *ConfigMapTargetProvider) Init(config providers.IProviderConfig) error { if i.Config.ConfigData != "" { kConfig, err = clientcmd.RESTConfigFromKubeConfig([]byte(i.Config.ConfigData)) if err != nil { - sLog.Errorf(" P (ConfigMap Target): %+v", err) + sLog.Errorf(" P (ConfigMap Target): failed to read kube config: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } } else { err = v1alpha2.NewCOAError(nil, "config data is not supplied", v1alpha2.BadConfig) - sLog.Errorf(" P (ConfigMap Target): %+v", err) + sLog.Errorf(" P (ConfigMap Target): %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } default: err = v1alpha2.NewCOAError(nil, "unrecognized config type, accepted values are: path and inline", v1alpha2.BadConfig) - sLog.Errorf(" P (ConfigMap Target): %+v", err) + sLog.Errorf(" P (ConfigMap Target): %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } } if err != nil { - sLog.Errorf(" P (ConfigMap Target): %+v", err) + sLog.Errorf(" P (ConfigMap Target): failed to get the cluster config: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } i.Client, err = kubernetes.NewForConfig(kConfig) if err != nil { - sLog.Errorf(" P (ConfigMap Target): %+v", err) + sLog.Errorf(" P (ConfigMap Target): failed to create a new clientset: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } i.DynamicClient, err = dynamic.NewForConfig(kConfig) if err != nil { - sLog.Errorf(" P (ConfigMap Target): %+v", err) + sLog.Errorf(" P (ConfigMap Target): failed to create a dynamic client: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } i.DiscoveryClient, err = discovery.NewDiscoveryClientForConfig(kConfig) if err != nil { - sLog.Errorf(" P (ConfigMap Target): %+v", err) + sLog.Errorf(" P (ConfigMap Target): failed to create a discovery client: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } @@ -207,7 +208,7 @@ func (i *ConfigMapTargetProvider) Get(ctx context.Context, deployment model.Depl ) var err error = nil defer utils.CloseSpanWithError(span, &err) - sLog.Infof(" P (ConfigMap Target): getting artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (ConfigMap Target): getting artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) ret := make([]model.ComponentSpec, 0) for _, component := range references { @@ -215,10 +216,10 @@ func (i *ConfigMapTargetProvider) Get(ctx context.Context, deployment model.Depl obj, err = i.Client.CoreV1().ConfigMaps(deployment.Instance.Scope).Get(ctx, component.Component.Name, metav1.GetOptions{}) if err != nil { if kerrors.IsNotFound(err) { - sLog.Infof(" P (ConfigMap Target): resource not found: %s", err) + sLog.Infof(" P (ConfigMap Target): resource not found: %s, traceId: %s", err, span.SpanContext().TraceID().String()) continue } - sLog.Error(" P (ConfigMap Target): failed to read object: +%v", err) + sLog.Error(" P (ConfigMap Target): failed to read object: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } component.Component.Properties = make(map[string]interface{}) @@ -249,7 +250,7 @@ func (i *ConfigMapTargetProvider) Apply(ctx context.Context, deployment model.De var err error = nil defer utils.CloseSpanWithError(span, &err) - sLog.Infof(" P (ConfigMap Target): applying artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (ConfigMap Target): applying artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) components := step.GetComponents() err = i.GetValidationRule(ctx).Validate(components) @@ -284,7 +285,7 @@ func (i *ConfigMapTargetProvider) Apply(ctx context.Context, deployment model.De i.ensureNamespace(ctx, deployment.Instance.Scope) err = i.applyConfigMap(ctx, newConfigMap, deployment.Instance.Scope) if err != nil { - sLog.Error(" P (ConfigMap Target): failed to apply configmap: +%v", err) + sLog.Error(" P (ConfigMap Target): failed to apply configmap: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } @@ -296,7 +297,7 @@ func (i *ConfigMapTargetProvider) Apply(ctx context.Context, deployment model.De if component.Type == "config" { err = i.deleteConfigMap(ctx, component.Name, deployment.Instance.Scope) if err != nil { - sLog.Error(" P (ConfigMap Target): failed to delete configmap: +%v", err) + sLog.Error(" P (ConfigMap Target): failed to delete configmap: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } @@ -316,6 +317,7 @@ func (k *ConfigMapTargetProvider) ensureNamespace(ctx context.Context, namespace ) var err error = nil defer utils.CloseSpanWithError(span, &err) + sLog.Infof(" P (ConfigMap Target): ensureNamespace namespace - %s, traceId: %s", namespace, span.SpanContext().TraceID().String()) _, err = k.Client.CoreV1().Namespaces().Get(ctx, namespace, metav1.GetOptions{}) if err == nil { @@ -329,12 +331,11 @@ func (k *ConfigMapTargetProvider) ensureNamespace(ctx context.Context, namespace }, }, metav1.CreateOptions{}) if err != nil { - sLog.Error(" P (ConfigMap Target): failed to create namespace: +%v", err) + sLog.Error(" P (ConfigMap Target): failed to create namespace: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } - } else { - sLog.Error(" P (ConfigMap Target): failed to get namespace: +%v", err) + sLog.Error(" P (ConfigMap Target): failed to get namespace: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } @@ -359,10 +360,21 @@ func (*ConfigMapTargetProvider) GetValidationRule(ctx context.Context) model.Val // deleteConfigMap deletes a configmap func (i *ConfigMapTargetProvider) deleteConfigMap(ctx context.Context, name string, scope string) error { - err := i.Client.CoreV1().ConfigMaps(scope).Delete(ctx, name, metav1.DeleteOptions{}) + ctx, span := observability.StartSpan( + "ConfigMap Target Provider", + ctx, + &map[string]string{ + "method": "deleteConfigMap", + }, + ) + var err error = nil + defer utils.CloseSpanWithError(span, &err) + sLog.Infof(" P (ConfigMap Target): deleteConfigMap name %s, scope: %s, traceId: %s", name, scope, span.SpanContext().TraceID().String()) + + err = i.Client.CoreV1().ConfigMaps(scope).Delete(ctx, name, metav1.DeleteOptions{}) if err != nil { if !kerrors.IsNotFound(err) { - sLog.Error(" P (Kubectl Target): failed to delete configmap: +%v", err) + sLog.Error(" P (Kubectl Target): failed to delete configmap: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } } @@ -371,18 +383,29 @@ func (i *ConfigMapTargetProvider) deleteConfigMap(ctx context.Context, name stri // applyCustomResource applies a custom resource from a byte array func (i *ConfigMapTargetProvider) applyConfigMap(ctx context.Context, config *corev1.ConfigMap, scope string) error { + ctx, span := observability.StartSpan( + "ConfigMap Target Provider", + ctx, + &map[string]string{ + "method": "applyConfigMap", + }, + ) + var err error = nil + defer utils.CloseSpanWithError(span, &err) + sLog.Infof(" P (ConfigMap Target): applyConfigMap scope: %s, traceId: %s", scope, span.SpanContext().TraceID().String()) + existingConfigMap, err := i.Client.CoreV1().ConfigMaps(scope).Get(ctx, config.Name, metav1.GetOptions{}) if err != nil { if kerrors.IsNotFound(err) { sLog.Infof(" P (ConfigMap Target): resource not found: %s", err) _, err = i.Client.CoreV1().ConfigMaps(scope).Create(ctx, config, metav1.CreateOptions{}) if err != nil { - sLog.Error(" P (ConfigMap Target): failed to create configmap: +%v", err) + sLog.Error(" P (ConfigMap Target): failed to create configmap: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } return nil } - sLog.Error(" P (ConfigMap Target): failed to read object: +%v", err) + sLog.Error(" P (ConfigMap Target): failed to read object: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } @@ -390,7 +413,7 @@ func (i *ConfigMapTargetProvider) applyConfigMap(ctx context.Context, config *co _, err = i.Client.CoreV1().ConfigMaps(scope).Update(ctx, existingConfigMap, metav1.UpdateOptions{}) if err != nil { - sLog.Error(" P (ConfigMap Target): failed to update configmap: +%v", err) + sLog.Error(" P (ConfigMap Target): failed to update configmap: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } return nil diff --git a/api/pkg/apis/v1alpha1/providers/target/docker/docker.go b/api/pkg/apis/v1alpha1/providers/target/docker/docker.go index da7cecd3e..da469cee1 100644 --- a/api/pkg/apis/v1alpha1/providers/target/docker/docker.go +++ b/api/pkg/apis/v1alpha1/providers/target/docker/docker.go @@ -89,11 +89,11 @@ func (i *DockerTargetProvider) Get(ctx context.Context, deployment model.Deploym var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Infof(" P (Docker Target): getting artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (Docker Target): getting artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) cli, err := client.NewClientWithOpts(client.FromEnv) if err != nil { - sLog.Errorf(" P (Docker Target): failed to create docker client: %+v", err) + sLog.Errorf(" P (Docker Target): failed to create docker client: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } @@ -168,7 +168,7 @@ func (i *DockerTargetProvider) Apply(ctx context.Context, deployment model.Deplo var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Infof(" P (Docker Target): applying artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (Docker Target): applying artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) injections := &model.ValueInjections{ InstanceId: deployment.Instance.Name, @@ -179,6 +179,7 @@ func (i *DockerTargetProvider) Apply(ctx context.Context, deployment model.Deplo components := step.GetComponents() err = i.GetValidationRule(ctx).Validate(components) if err != nil { + sLog.Errorf(" P (Docker Target): failed to validate components: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } if isDryRun { @@ -190,7 +191,7 @@ func (i *DockerTargetProvider) Apply(ctx context.Context, deployment model.Deplo cli, err := client.NewClientWithOpts(client.FromEnv) if err != nil { - sLog.Errorf(" P (Docker Target): failed to create docker client: %+v", err) + sLog.Errorf(" P (Docker Target): failed to create docker client: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } @@ -204,7 +205,7 @@ func (i *DockerTargetProvider) Apply(ctx context.Context, deployment model.Deplo Status: v1alpha2.UpdateFailed, Message: err.Error(), } - sLog.Errorf(" P (Helm Target): component doesn't have container.image property") + sLog.Errorf(" P (Helm Target): %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } @@ -229,7 +230,7 @@ func (i *DockerTargetProvider) Apply(ctx context.Context, deployment model.Deplo err = cli.ContainerStop(context.TODO(), component.Component.Name, nil) if err != nil { if !client.IsErrNotFound(err) { - sLog.Errorf(" P (Docker Target): failed to stop a running container: %+v", err) + sLog.Errorf(" P (Docker Target): failed to stop a running container: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } @@ -239,7 +240,7 @@ func (i *DockerTargetProvider) Apply(ctx context.Context, deployment model.Deplo Status: v1alpha2.UpdateFailed, Message: err.Error(), } - sLog.Errorf(" P (Docker Target): failed to remove existing container: %+v", err) + sLog.Errorf(" P (Docker Target): failed to remove existing container: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } @@ -265,7 +266,7 @@ func (i *DockerTargetProvider) Apply(ctx context.Context, deployment model.Deplo Status: v1alpha2.UpdateFailed, Message: err.Error(), } - sLog.Errorf(" P (Docker Target): failed to read container resource settings: %+v", err) + sLog.Errorf(" P (Docker Target): failed to read container resource settings: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } hostConfig = &container.HostConfig{ @@ -279,7 +280,7 @@ func (i *DockerTargetProvider) Apply(ctx context.Context, deployment model.Deplo Status: v1alpha2.UpdateFailed, Message: err.Error(), } - sLog.Errorf(" P (Docker Target): failed to create container: %+v", err) + sLog.Errorf(" P (Docker Target): failed to create container: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } @@ -288,7 +289,7 @@ func (i *DockerTargetProvider) Apply(ctx context.Context, deployment model.Deplo Status: v1alpha2.UpdateFailed, Message: err.Error(), } - sLog.Errorf(" P (Docker Target): failed to start container: %+v", err) + sLog.Errorf(" P (Docker Target): failed to start container: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } ret[component.Component.Name] = model.ComponentResultSpec{ @@ -299,14 +300,14 @@ func (i *DockerTargetProvider) Apply(ctx context.Context, deployment model.Deplo err = cli.ContainerStop(context.TODO(), component.Component.Name, nil) if err != nil { if !client.IsErrNotFound(err) { - sLog.Errorf(" P (Docker Target): failed to stop a running container: %+v", err) + sLog.Errorf(" P (Docker Target): failed to stop a running container: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } err = cli.ContainerRemove(context.TODO(), component.Component.Name, types.ContainerRemoveOptions{}) if err != nil { if !client.IsErrNotFound(err) { - sLog.Errorf(" P (Docker Target): failed to remove existing container: %+v", err) + sLog.Errorf(" P (Docker Target): failed to remove existing container: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } diff --git a/api/pkg/apis/v1alpha1/providers/target/helm/helm.go b/api/pkg/apis/v1alpha1/providers/target/helm/helm.go index 0dcdb2190..f8e7c790b 100644 --- a/api/pkg/apis/v1alpha1/providers/target/helm/helm.go +++ b/api/pkg/apis/v1alpha1/providers/target/helm/helm.go @@ -239,12 +239,12 @@ func (i *HelmTargetProvider) Get(ctx context.Context, deployment model.Deploymen ) var err error defer utils.CloseSpanWithError(span, &err) - sLog.Infof(" P (Helm Target): getting artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (Helm Target): getting artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) i.ListClient.Deployed = true var results []*release.Release results, err = i.ListClient.Run() if err != nil { - sLog.Errorf(" P (Helm Target): failed to create Helm list client: %+v", err) + sLog.Errorf(" P (Helm Target): failed to create Helm list client: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } @@ -318,11 +318,12 @@ func (i *HelmTargetProvider) Apply(ctx context.Context, deployment model.Deploym ) var err error defer utils.CloseSpanWithError(span, &err) - sLog.Infof(" P (Helm Target): applying artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (Helm Target): applying artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) components := step.GetComponents() err = i.GetValidationRule(ctx).Validate(components) if err != nil { + sLog.Errorf(" P (Helm Target): failed to validate components: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } @@ -337,7 +338,7 @@ func (i *HelmTargetProvider) Apply(ctx context.Context, deployment model.Deploym var helmProp *HelmProperty helmProp, err = getHelmPropertyFromComponent(component.Component) if err != nil { - sLog.Errorf(" P (Helm Target): failed to get Helm properties: %+v", err) + sLog.Errorf(" P (Helm Target): failed to get Helm properties: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) ret[component.Component.Name] = model.ComponentResultSpec{ Status: v1alpha2.UpdateFailed, Message: err.Error(), @@ -348,7 +349,7 @@ func (i *HelmTargetProvider) Apply(ctx context.Context, deployment model.Deploym var fileName string fileName, err = i.pullChart(&helmProp.Chart) if err != nil { - sLog.Errorf(" P (Helm Target): failed to pull chart: %+v", err) + sLog.Errorf(" P (Helm Target): failed to pull chart: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) ret[component.Component.Name] = model.ComponentResultSpec{ Status: v1alpha2.UpdateFailed, Message: err.Error(), @@ -360,7 +361,7 @@ func (i *HelmTargetProvider) Apply(ctx context.Context, deployment model.Deploym var chart *chart.Chart chart, err = loader.Load(fileName) if err != nil { - sLog.Errorf(" P (Helm Target): failed to load chart: %+v", err) + sLog.Errorf(" P (Helm Target): failed to load chart: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) ret[component.Component.Name] = model.ComponentResultSpec{ Status: v1alpha2.UpdateFailed, Message: err.Error(), @@ -373,7 +374,7 @@ func (i *HelmTargetProvider) Apply(ctx context.Context, deployment model.Deploym if _, err = i.UpgradeClient.Run(component.Component.Name, chart, helmProp.Values); err != nil { if _, err = i.InstallClient.Run(chart, helmProp.Values); err != nil { - sLog.Errorf(" P (Helm Target): failed to apply: %+v", err) + sLog.Errorf(" P (Helm Target): failed to apply: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) ret[component.Component.Name] = model.ComponentResultSpec{ Status: v1alpha2.UpdateFailed, Message: err.Error(), @@ -396,7 +397,7 @@ func (i *HelmTargetProvider) Apply(ctx context.Context, deployment model.Deploym Status: v1alpha2.DeleteFailed, Message: err.Error(), } - sLog.Errorf(" P (Helm Target): failed to uninstall Helm chart: %+v", err) + sLog.Errorf(" P (Helm Target): failed to uninstall Helm chart: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } ret[component.Component.Name] = model.ComponentResultSpec{ diff --git a/api/pkg/apis/v1alpha1/providers/target/http/http.go b/api/pkg/apis/v1alpha1/providers/target/http/http.go index 71fe17846..d129ea6d9 100644 --- a/api/pkg/apis/v1alpha1/providers/target/http/http.go +++ b/api/pkg/apis/v1alpha1/providers/target/http/http.go @@ -88,7 +88,7 @@ func (i *HttpTargetProvider) Get(ctx context.Context, deployment model.Deploymen var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Infof(" P(HTTP Target): getting artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P(HTTP Target): getting artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) // This provider doesn't remember what it does, so it always return nil when asked return nil, nil @@ -101,7 +101,7 @@ func (i *HttpTargetProvider) Apply(ctx context.Context, deployment model.Deploym var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Infof(" P(HTTP Target): applying artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P(HTTP Target): applying artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) injections := &model.ValueInjections{ InstanceId: deployment.Instance.Name, @@ -112,6 +112,7 @@ func (i *HttpTargetProvider) Apply(ctx context.Context, deployment model.Deploym components := step.GetComponents() err = i.GetValidationRule(ctx).Validate(components) if err != nil { + sLog.Errorf(" P (HTTP Target): failed to validate components: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } if isDryRun { @@ -132,7 +133,7 @@ func (i *HttpTargetProvider) Apply(ctx context.Context, deployment model.Deploym Status: v1alpha2.UpdateFailed, Message: err.Error(), } - sLog.Errorf(" P(HTTP Target): %v", err) + sLog.Errorf(" P(HTTP Target): %v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } if method == "" { @@ -146,7 +147,7 @@ func (i *HttpTargetProvider) Apply(ctx context.Context, deployment model.Deploym Status: v1alpha2.UpdateFailed, Message: err.Error(), } - sLog.Errorf(" P(HTTP Target): %v", err) + sLog.Errorf(" P(HTTP Target): %v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } request.Header.Set("Content-Type", "application/json; charset=UTF-8") @@ -159,7 +160,7 @@ func (i *HttpTargetProvider) Apply(ctx context.Context, deployment model.Deploym Status: v1alpha2.UpdateFailed, Message: err.Error(), } - sLog.Errorf(" P(HTTP Target): %v", err) + sLog.Errorf(" P(HTTP Target): %v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } if resp.StatusCode != http.StatusOK { @@ -175,7 +176,7 @@ func (i *HttpTargetProvider) Apply(ctx context.Context, deployment model.Deploym Message: message, } err = errors.New("HTTP request didn't respond 200 OK") - sLog.Errorf(" P(HTTP Target): %v", err) + sLog.Errorf(" P(HTTP Target): %v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } diff --git a/api/pkg/apis/v1alpha1/providers/target/ingress/ingress.go b/api/pkg/apis/v1alpha1/providers/target/ingress/ingress.go index c861d4580..3aad923ff 100644 --- a/api/pkg/apis/v1alpha1/providers/target/ingress/ingress.go +++ b/api/pkg/apis/v1alpha1/providers/target/ingress/ingress.go @@ -108,7 +108,7 @@ func (i *IngressTargetProvider) InitWithMap(properties map[string]string) error // Init initializes the ingress target provider func (i *IngressTargetProvider) Init(config providers.IProviderConfig) error { _, span := observability.StartSpan( - "ConfigMap Target Provider", + "Ingress Target Provider", context.TODO(), &map[string]string{ "method": "Init", @@ -116,11 +116,11 @@ func (i *IngressTargetProvider) Init(config providers.IProviderConfig) error { ) var err error defer utils.CloseSpanWithError(span, &err) - sLog.Info(" P (ConfigMap Target): Init()") + sLog.Info(" P (Ingress Target): Init()") updateConfig, err := toIngressTargetProviderConfig(config) if err != nil { - sLog.Errorf(" P (ConfigMap Target): expected IngressTargetProviderConfig - %+v", err) + sLog.Errorf(" P (Ingress Target): expected IngressTargetProviderConfig - %+v", err) return err } @@ -160,25 +160,25 @@ func (i *IngressTargetProvider) Init(config providers.IProviderConfig) error { } } if err != nil { - sLog.Errorf(" P (Ingress Target): %+v", err) + sLog.Errorf(" P (Ingress Target): failed to get the cluster config: %+v", err) return err } i.Client, err = kubernetes.NewForConfig(kConfig) if err != nil { - sLog.Errorf(" P (Ingress Target): %+v", err) + sLog.Errorf(" P (Ingress Target): failed to create a new clientset: %+v", err) return err } i.DynamicClient, err = dynamic.NewForConfig(kConfig) if err != nil { - sLog.Errorf(" P (Ingress Target): %+v", err) + sLog.Errorf(" P (Ingress Target): failed to create a dynamic client: %+v", err) return err } i.DiscoveryClient, err = discovery.NewDiscoveryClientForConfig(kConfig) if err != nil { - sLog.Errorf(" P (Ingress Target): %+v", err) + sLog.Errorf(" P (Ingress Target): failed to create a discovery client: %+v", err) return err } @@ -209,7 +209,7 @@ func (i *IngressTargetProvider) Get(ctx context.Context, deployment model.Deploy ) var err error defer utils.CloseSpanWithError(span, &err) - sLog.Infof(" P (Ingress Target): getting artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (Ingress Target): getting artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) ret := make([]model.ComponentSpec, 0) for _, component := range references { @@ -217,10 +217,10 @@ func (i *IngressTargetProvider) Get(ctx context.Context, deployment model.Deploy obj, err = i.Client.NetworkingV1().Ingresses(deployment.Instance.Scope).Get(ctx, component.Component.Name, metav1.GetOptions{}) if err != nil { if kerrors.IsNotFound(err) { - sLog.Infof(" P (Ingress Target): resource not found: %s", err) + sLog.Infof(" P (Ingress Target): resource not found: %v, traceId: %s", err, span.SpanContext().TraceID().String()) continue } - sLog.Error(" P (Ingress Target): failed to read object: +%v", err) + sLog.Error(" P (Ingress Target): failed to read object: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } component.Component.Properties = make(map[string]interface{}) @@ -243,7 +243,7 @@ func (i *IngressTargetProvider) Apply(ctx context.Context, deployment model.Depl ) var err error defer utils.CloseSpanWithError(span, &err) - sLog.Infof(" P (Ingress Target): applying artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (Ingress Target): applying artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) components := step.GetComponents() err = i.GetValidationRule(ctx).Validate(components) @@ -273,7 +273,7 @@ func (i *IngressTargetProvider) Apply(ctx context.Context, deployment model.Depl var rules []networkingv1.IngressRule err = json.Unmarshal(jData, &rules) if err != nil { - sLog.Error(" P (Ingress Target): failed to unmarshal ingress: +%v", err) + sLog.Error(" P (Ingress Target): failed to unmarshal ingress: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } newIngress.Spec.Rules = rules @@ -284,7 +284,7 @@ func (i *IngressTargetProvider) Apply(ctx context.Context, deployment model.Depl if ok { newIngress.Spec.IngressClassName = &s } else { - sLog.Error(" P (Ingress Target): failed to convert ingress class name: +%v", v) + sLog.Error(" P (Ingress Target): failed to convert ingress class name: +%v, traceId: %s", v, span.SpanContext().TraceID().String()) return ret, err } } @@ -301,7 +301,7 @@ func (i *IngressTargetProvider) Apply(ctx context.Context, deployment model.Depl i.ensureNamespace(ctx, deployment.Instance.Scope) err = i.applyIngress(ctx, newIngress, deployment.Instance.Scope) if err != nil { - sLog.Error(" P (Ingress Target): failed to apply ingress: +%v", err) + sLog.Error(" P (Ingress Target): failed to apply ingress: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } @@ -313,7 +313,7 @@ func (i *IngressTargetProvider) Apply(ctx context.Context, deployment model.Depl if component.Type == "ingress" { err = i.deleteIngress(ctx, component.Name, deployment.Instance.Scope) if err != nil { - sLog.Error(" P (Ingress Target): failed to delete ingress: +%v", err) + sLog.Error(" P (Ingress Target): failed to delete ingress: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } @@ -325,7 +325,7 @@ func (i *IngressTargetProvider) Apply(ctx context.Context, deployment model.Depl // ensureNamespace ensures that the namespace exists func (k *IngressTargetProvider) ensureNamespace(ctx context.Context, namespace string) error { _, span := observability.StartSpan( - "ConfigMap Target Provider", + "Ingress Target Provider", ctx, &map[string]string{ "method": "ensureNamespace", @@ -333,6 +333,7 @@ func (k *IngressTargetProvider) ensureNamespace(ctx context.Context, namespace s ) var err error defer utils.CloseSpanWithError(span, &err) + sLog.Infof(" P (Ingress Target): ensureNamespace %s, traceId: %s", namespace, span.SpanContext().TraceID().String()) _, err = k.Client.CoreV1().Namespaces().Get(ctx, namespace, metav1.GetOptions{}) if err == nil { @@ -346,12 +347,11 @@ func (k *IngressTargetProvider) ensureNamespace(ctx context.Context, namespace s }, }, metav1.CreateOptions{}) if err != nil { - sLog.Error(" P (ConfigMap Target): failed to create namespace: +%v", err) + sLog.Error(" P (Ingress Target): failed to create namespace: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } - } else { - sLog.Error(" P (ConfigMap Target): failed to get namespace: +%v", err) + sLog.Error(" P (Ingress Target): failed to get namespace: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } @@ -381,10 +381,21 @@ func (*IngressTargetProvider) GetValidationRule(ctx context.Context) model.Valid // deleteConfigMap deletes a configmap func (i *IngressTargetProvider) deleteIngress(ctx context.Context, name string, scope string) error { - err := i.Client.NetworkingV1().Ingresses(scope).Delete(ctx, name, metav1.DeleteOptions{}) + _, span := observability.StartSpan( + "Ingress Target Provider", + ctx, + &map[string]string{ + "method": "deleteIngress", + }, + ) + var err error + defer utils.CloseSpanWithError(span, &err) + sLog.Infof(" P (Ingress Target): deleteIngress name %s, scope %s, traceId: %s", name, scope, span.SpanContext().TraceID().String()) + + err = i.Client.NetworkingV1().Ingresses(scope).Delete(ctx, name, metav1.DeleteOptions{}) if err != nil { if !kerrors.IsNotFound(err) { - sLog.Error(" P (Ingress Target): failed to delete ingress: +%v", err) + sLog.Error(" P (Ingress Target): failed to delete ingress: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } } @@ -393,18 +404,29 @@ func (i *IngressTargetProvider) deleteIngress(ctx context.Context, name string, // applyCustomResource applies a custom resource from a byte array func (i *IngressTargetProvider) applyIngress(ctx context.Context, ingress *networkingv1.Ingress, scope string) error { + _, span := observability.StartSpan( + "Ingress Target Provider", + ctx, + &map[string]string{ + "method": "applyIngress", + }, + ) + var err error + defer utils.CloseSpanWithError(span, &err) + sLog.Infof(" P (Ingress Target): applyIngress scope %s, name %s, traceId: %s", scope, ingress.Name, span.SpanContext().TraceID().String()) + existingIngress, err := i.Client.NetworkingV1().Ingresses(scope).Get(ctx, ingress.Name, metav1.GetOptions{}) if err != nil { if kerrors.IsNotFound(err) { - sLog.Infof(" P (Ingress Target): resource not found: %s", err) + sLog.Infof(" P (Ingress Target): resource not found: %v, traceId: %s", err, span.SpanContext().TraceID().String()) _, err = i.Client.NetworkingV1().Ingresses(scope).Create(ctx, ingress, metav1.CreateOptions{}) if err != nil { - sLog.Error(" P (Ingress Target): failed to create ingress: +%v", err) + sLog.Error(" P (Ingress Target): failed to create ingress: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } return nil } - sLog.Error(" P (Ingress Target): failed to read object: +%v", err) + sLog.Error(" P (Ingress Target): failed to read object: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } @@ -414,7 +436,7 @@ func (i *IngressTargetProvider) applyIngress(ctx context.Context, ingress *netwo } _, err = i.Client.NetworkingV1().Ingresses(scope).Update(ctx, existingIngress, metav1.UpdateOptions{}) if err != nil { - sLog.Error(" P (Ingress Target): failed to update ingress: +%v", err) + sLog.Error(" P (Ingress Target): failed to update ingress: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } return nil diff --git a/api/pkg/apis/v1alpha1/providers/target/k8s/k8s.go b/api/pkg/apis/v1alpha1/providers/target/k8s/k8s.go index 11c33350b..8692a5051 100644 --- a/api/pkg/apis/v1alpha1/providers/target/k8s/k8s.go +++ b/api/pkg/apis/v1alpha1/providers/target/k8s/k8s.go @@ -144,8 +144,20 @@ func (s *K8sTargetProvider) SetContext(ctx *contexts.ManagerContext) { } func (i *K8sTargetProvider) Init(config providers.IProviderConfig) error { + _, span := observability.StartSpan( + "K8s Target Provider", + context.TODO(), + &map[string]string{ + "method": "Init", + }, + ) + var err error + defer observ_utils.CloseSpanWithError(span, &err) + log.Info(" P (K8s Target): Init()") + updateConfig, err := toK8sTargetProviderConfig(config) if err != nil { + log.Errorf(" P (K8s Target): expected K8sTargetProviderConfig - %+v", err) return errors.New("expected K8sTargetProviderConfig") } i.Config = updateConfig @@ -159,7 +171,9 @@ func (i *K8sTargetProvider) Init(config providers.IProviderConfig) error { if home := homedir.HomeDir(); home != "" { i.Config.ConfigData = filepath.Join(home, ".kube", "config") } else { - return v1alpha2.NewCOAError(nil, "can't locate home direction to read default kubernetes config file, to run in cluster, set inCluster config setting to true", v1alpha2.BadConfig) + err = v1alpha2.NewCOAError(nil, "can't locate home direction to read default kubernetes config file, to run in cluster, set inCluster config setting to true", v1alpha2.BadConfig) + log.Errorf(" P (K8s Target): %+v", err) + return err } } kConfig, err = clientcmd.BuildConfigFromFlags("", i.Config.ConfigData) @@ -167,24 +181,32 @@ func (i *K8sTargetProvider) Init(config providers.IProviderConfig) error { if i.Config.ConfigData != "" { kConfig, err = clientcmd.RESTConfigFromKubeConfig([]byte(i.Config.ConfigData)) if err != nil { + log.Errorf(" P (K8s Target): failed to get RESTconfg: %+v", err) return err } } else { - return v1alpha2.NewCOAError(nil, "config data is not supplied", v1alpha2.BadConfig) + err = v1alpha2.NewCOAError(nil, "config data is not supplied", v1alpha2.BadConfig) + log.Errorf(" P (K8s Target): %+v", err) + return err } default: - return v1alpha2.NewCOAError(nil, "unrecognized config type, accepted values are: path and bytes", v1alpha2.BadConfig) + err = v1alpha2.NewCOAError(nil, "unrecognized config type, accepted values are: path and inline", v1alpha2.BadConfig) + log.Errorf(" P (K8s Target): %+v", err) + return err } } if err != nil { + log.Errorf(" P (K8s Target): failed to get the cluster config: %+v", err) return err } i.Client, err = kubernetes.NewForConfig(kConfig) if err != nil { + log.Errorf(" P (K8s Target): failed to create a new clientset: %+v", err) return err } i.DynamicClient, err = dynamic.NewForConfig(kConfig) if err != nil { + log.Errorf(" P (K8s Target): failed to create a discovery client: %+v", err) return err } return nil @@ -202,16 +224,24 @@ func toK8sTargetProviderConfig(config providers.IProviderConfig) (K8sTargetProvi } func (i *K8sTargetProvider) getDeployment(ctx context.Context, scope string, name string) ([]model.ComponentSpec, error) { + _, span := observability.StartSpan("K8s Target Provider", ctx, &map[string]string{ + "method": "getDeployment", + }) + var err error = nil + defer observ_utils.CloseSpanWithError(span, &err) + log.Infof(" P (K8s Target Provider): getDeployment scope - %s, name - %s, traceId: %s", scope, name, span.SpanContext().TraceID().String()) + deployment, err := i.Client.AppsV1().Deployments(scope).Get(ctx, name, metav1.GetOptions{}) if err != nil { if k8s_errors.IsNotFound(err) { return nil, nil } + log.Errorf(" P (K8s Target Provider): getDeployment %s failed - %s", name, err.Error()) return nil, err } components, err := deploymentToComponents(*deployment) if err != nil { - log.Infof(" P (K8s Target Provider): getDeployment failed - %s", err.Error()) + log.Errorf(" P (K8s Target Provider): getDeployment failed - %s", err.Error()) return nil, err } return components, nil @@ -247,7 +277,7 @@ func (i *K8sTargetProvider) Get(ctx context.Context, dep model.DeploymentSpec, r }) var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - log.Infof(" P (K8s Target Provider): getting artifacts: %s - %s", dep.Instance.Scope, dep.Instance.Name) + log.Infof(" P (K8s Target Provider): getting artifacts: %s - %s, traceId: %s", dep.Instance.Scope, dep.Instance.Name, span.SpanContext().TraceID().String()) var components []model.ComponentSpec @@ -255,7 +285,7 @@ func (i *K8sTargetProvider) Get(ctx context.Context, dep model.DeploymentSpec, r case "", SINGLE_POD: components, err = i.getDeployment(ctx, dep.Instance.Scope, dep.Instance.Name) if err != nil { - log.Debugf(" P (K8s Target Provider): failed to get - %s", err.Error()) + log.Debugf(" P (K8s Target Provider): failed to get - %s, traceId: %s", err.Error(), span.SpanContext().TraceID().String()) return nil, err } case SERVICES, SERVICES_NS: @@ -269,7 +299,7 @@ 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.Debugf(" P (K8s Target Provider) - failed to get: %s", err.Error()) + log.Debugf(" P (K8s Target Provider) - failed to get: %s, traceId: %s", err.Error(), span.SpanContext().TraceID().String()) return nil, err } if len(cComponents) > 1 { @@ -301,6 +331,13 @@ func (i *K8sTargetProvider) Get(ctx context.Context, dep model.DeploymentSpec, r return components, nil } func (i *K8sTargetProvider) removeService(ctx context.Context, scope string, serviceName string) error { + _, span := observability.StartSpan("K8s Target Provider", ctx, &map[string]string{ + "method": "removeService", + }) + var err error = nil + defer observ_utils.CloseSpanWithError(span, &err) + log.Infof(" P (K8s Target Provider): removeService scope - %s, serviceName - %s", scope, serviceName) + svc, err := i.Client.CoreV1().Services(scope).Get(ctx, serviceName, metav1.GetOptions{}) if err == nil && svc != nil { foregroundDeletion := metav1.DeletePropagationForeground @@ -314,8 +351,15 @@ func (i *K8sTargetProvider) removeService(ctx context.Context, scope string, ser return nil } func (i *K8sTargetProvider) removeDeployment(ctx context.Context, scope string, name string) error { + _, span := observability.StartSpan("K8s Target Provider", ctx, &map[string]string{ + "method": "removeDeployment", + }) + var err error = nil + defer observ_utils.CloseSpanWithError(span, &err) + log.Infof(" P (K8s Target Provider): removeDeployment scope - %s, name - %s", scope, name) + foregroundDeletion := metav1.DeletePropagationForeground - err := i.Client.AppsV1().Deployments(scope).Delete(ctx, name, metav1.DeleteOptions{PropagationPolicy: &foregroundDeletion}) + err = i.Client.AppsV1().Deployments(scope).Delete(ctx, name, metav1.DeleteOptions{PropagationPolicy: &foregroundDeletion}) if err != nil { if !k8s_errors.IsNotFound(err) { return err @@ -325,7 +369,14 @@ func (i *K8sTargetProvider) removeDeployment(ctx context.Context, scope string, return nil } func (i *K8sTargetProvider) removeNamespace(ctx context.Context, scope string, retryCount int, retryIntervalInSec int) error { - _, err := i.Client.CoreV1().Namespaces().Get(ctx, scope, metav1.GetOptions{}) + _, span := observability.StartSpan("K8s Target Provider", ctx, &map[string]string{ + "method": "removeNamespace", + }) + var err error = nil + defer observ_utils.CloseSpanWithError(span, &err) + log.Infof(" P (K8s Target Provider): removeNamespace scope - %s, traceId: %s", scope, span.SpanContext().TraceID().String()) + + _, err = i.Client.CoreV1().Namespaces().Get(ctx, scope, metav1.GetOptions{}) if err != nil { return err } @@ -400,7 +451,14 @@ func (i *K8sTargetProvider) removeNamespace(ctx context.Context, scope string, r return nil } func (i *K8sTargetProvider) createNamespace(ctx context.Context, scope string) error { - _, err := i.Client.CoreV1().Namespaces().Get(ctx, scope, metav1.GetOptions{}) + _, span := observability.StartSpan("K8s Target Provider", ctx, &map[string]string{ + "method": "createNamespace", + }) + var err error = nil + defer observ_utils.CloseSpanWithError(span, &err) + log.Infof(" P (K8s Target Provider): removeDeployment scope - %s", scope) + + _, err = i.Client.CoreV1().Namespaces().Get(ctx, scope, metav1.GetOptions{}) if err != nil { if k8s_errors.IsNotFound(err) { _, err = i.Client.CoreV1().Namespaces().Create(ctx, &apiv1.Namespace{ @@ -418,6 +476,13 @@ func (i *K8sTargetProvider) createNamespace(ctx context.Context, scope string) e return nil } func (i *K8sTargetProvider) upsertDeployment(ctx context.Context, scope string, name string, deployment *v1.Deployment) error { + _, span := observability.StartSpan("K8s Target Provider", ctx, &map[string]string{ + "method": "upsertDeployment", + }) + var err error = nil + defer observ_utils.CloseSpanWithError(span, &err) + log.Infof(" P (K8s Target Provider): upsertDeployment scope - %s, name - %s, traceId: %s", scope, name, span.SpanContext().TraceID().String()) + existing, err := i.Client.AppsV1().Deployments(scope).Get(ctx, name, metav1.GetOptions{}) if err != nil && !k8s_errors.IsNotFound(err) { return err @@ -434,6 +499,13 @@ func (i *K8sTargetProvider) upsertDeployment(ctx context.Context, scope string, return nil } func (i *K8sTargetProvider) upsertService(ctx context.Context, scope string, name string, service *apiv1.Service) error { + _, span := observability.StartSpan("K8s Target Provider", ctx, &map[string]string{ + "method": "upsertService", + }) + var err error = nil + defer observ_utils.CloseSpanWithError(span, &err) + log.Infof(" P (K8s Target Provider): upsertService scope - %s, name - %s, traceId: %s", scope, name, span.SpanContext().TraceID().String()) + existing, err := i.Client.CoreV1().Services(scope).Get(ctx, name, metav1.GetOptions{}) if err != nil && !k8s_errors.IsNotFound(err) { return err @@ -452,28 +524,29 @@ func (i *K8sTargetProvider) upsertService(ctx context.Context, scope string, nam func (i *K8sTargetProvider) deployComponents(ctx context.Context, span trace.Span, scope string, name string, metadata map[string]string, components []model.ComponentSpec, projector IK8sProjector, instanceName string) error { var err error = nil defer observ_utils.CloseSpanWithError(span, &err) + log.Infof(" P (K8s Target Provider): deployComponents scope - %s, name - %s, traceId: %s", scope, name, span.SpanContext().TraceID().String()) deployment, err := componentsToDeployment(scope, name, metadata, components, instanceName) if projector != nil { err = projector.ProjectDeployment(scope, name, metadata, components, deployment) if err != nil { - log.Debugf(" P (K8s Target Provider): failed to project deployment: %s", err.Error()) + log.Debugf(" P (K8s Target Provider): failed to project deployment: %s, traceId: %s", err.Error(), span.SpanContext().TraceID().String()) return err } } if err != nil { - log.Debugf(" P (K8s Target Provider): failed to apply: %s", err.Error()) + log.Debugf(" P (K8s Target Provider): failed to apply: %s, traceId: %s", err.Error(), span.SpanContext().TraceID().String()) return err } service, err := metadataToService(scope, name, metadata) if err != nil { - log.Debugf(" P (K8s Target Provider): failed to apply (convert): %s", err.Error()) + log.Debugf(" P (K8s Target Provider): failed to apply (convert): %s, traceId: %s", err.Error(), span.SpanContext().TraceID().String()) return err } if projector != nil { err = projector.ProjectService(scope, name, metadata, service) if err != nil { - log.Debugf(" P (K8s Target Provider): failed to project service: %s", err.Error()) + log.Debugf(" P (K8s Target Provider): failed to project service: %s, traceId: %s", err.Error(), span.SpanContext().TraceID().String()) return err } } @@ -481,14 +554,14 @@ func (i *K8sTargetProvider) deployComponents(ctx context.Context, span trace.Spa log.Debug(" P (K8s Target Provider): checking namespace") err = i.createNamespace(ctx, scope) if err != nil { - log.Debugf("failed to create namespace: %s", err.Error()) + log.Debugf(" P (K8s Target Provider): failed to create namespace: %s, traceId: %s", err.Error(), span.SpanContext().TraceID().String()) return err } log.Debug(" P (K8s Target Provider): creating deployment") err = i.upsertDeployment(ctx, scope, name, deployment) if err != nil { - log.Debugf(" P (K8s Target Provider): failed to apply (API): %s", err.Error()) + log.Debugf(" P (K8s Target Provider): failed to apply (API): %s, traceId: %s", err.Error(), span.SpanContext().TraceID().String()) return err } @@ -496,7 +569,7 @@ func (i *K8sTargetProvider) deployComponents(ctx context.Context, span trace.Spa log.Debug(" P (K8s Target Provider): creating service") err = i.upsertService(ctx, scope, service.Name, service) if err != nil { - log.Debugf(" P (K8s Target Provider): failed to apply (service): %s", err.Error()) + log.Debugf(" P (K8s Target Provider): failed to apply (service): %s, traceId: %s", err.Error(), span.SpanContext().TraceID().String()) return err } } @@ -522,15 +595,15 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - log.Infof(" P (K8s Target Provider): applying artifacts: %s - %s", dep.Instance.Scope, dep.Instance.Name) + log.Infof(" P (K8s Target Provider): applying artifacts: %s - %s, traceId: %s", dep.Instance.Scope, dep.Instance.Name, span.SpanContext().TraceID().String()) components := step.GetComponents() err = i.GetValidationRule(ctx).Validate(components) if err != nil { + log.Errorf(" P (K8s Target Provider): failed to validate components, error: %v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } if isDryRun { - err = nil return nil, nil } @@ -538,7 +611,7 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, projector, err := createProjector(i.Config.Projector) if err != nil { - log.Debugf(" P (K8s Target Provider): failed to create projector: %s", err.Error()) + log.Debugf(" P (K8s Target Provider): failed to create projector: %s, traceId: %s", err.Error(), span.SpanContext().TraceID().String()) return ret, err } @@ -548,7 +621,7 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, if len(updated) > 0 { err = i.deployComponents(ctx, span, dep.Instance.Scope, dep.Instance.Name, dep.Instance.Metadata, components, projector, dep.Instance.Name) if err != nil { - log.Debugf(" P (K8s Target Provider): failed to apply components: %s", err.Error()) + log.Debugf(" P (K8s Target Provider): failed to apply components: %s, traceId: %s", err.Error(), span.SpanContext().TraceID().String()) return ret, err } } @@ -560,18 +633,18 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, } err = i.removeService(ctx, dep.Instance.Scope, serviceName) if err != nil { - log.Debugf("failed to remove service: %s", err.Error()) + log.Debugf(" P (K8s Target Provider): failed to remove service: %s, traceId: %s", err.Error(), span.SpanContext().TraceID().String()) return ret, err } err = i.removeDeployment(ctx, dep.Instance.Scope, dep.Instance.Name) if err != nil { - log.Debugf("failed to remove deployment: %s", err.Error()) + log.Debugf(" P (K8s Target Provider): failed to remove deployment: %s, traceId: %s", err.Error(), span.SpanContext().TraceID().String()) return ret, err } if i.Config.DeleteEmptyNamespace { err = i.removeNamespace(ctx, dep.Instance.Scope, i.Config.RetryCount, i.Config.RetryIntervalInSec) if err != nil { - log.Debugf("failed to remove namespace: %s", err.Error()) + log.Debugf(" P (K8s Target Provider): failed to remove namespace: %s, traceId: %s", err.Error(), span.SpanContext().TraceID().String()) } } } @@ -593,7 +666,7 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, } err = i.deployComponents(ctx, span, scope, component.Name, component.Metadata, []model.ComponentSpec{component}, projector, dep.Instance.Name) if err != nil { - log.Debugf(" P (K8s Target Provider): failed to apply components: %s", err.Error()) + log.Debugf(" P (K8s Target Provider): failed to apply components: %s, traceId: %s", err.Error(), span.SpanContext().TraceID().String()) return ret, err } } @@ -617,7 +690,7 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, Status: v1alpha2.DeleteFailed, Message: err.Error(), } - log.Debugf("failed to remove service: %s", err.Error()) + log.Debugf("P (K8s Target Provider): failed to remove service: %s, traceId: %s", err.Error(), span.SpanContext().TraceID().String()) return ret, err } err = i.removeDeployment(ctx, scope, component.Name) @@ -626,13 +699,13 @@ func (i *K8sTargetProvider) Apply(ctx context.Context, dep model.DeploymentSpec, Status: v1alpha2.DeleteFailed, Message: err.Error(), } - log.Debugf("failed to remove deployment: %s", err.Error()) + log.Debugf("P (K8s Target Provider): failed to remove deployment: %s, traceId: %", err.Error(), span.SpanContext().TraceID().String()) return ret, err } if i.Config.DeleteEmptyNamespace { err = i.removeNamespace(ctx, dep.Instance.Scope, i.Config.RetryCount, i.Config.RetryIntervalInSec) if err != nil { - log.Debugf("failed to remove namespace: %s", err.Error()) + log.Debugf("P (K8s Target Provider): failed to remove namespace: %s, traceId: %", err.Error(), span.SpanContext().TraceID().String()) } } } diff --git a/api/pkg/apis/v1alpha1/providers/target/kubectl/kubectl.go b/api/pkg/apis/v1alpha1/providers/target/kubectl/kubectl.go index bf56bbe94..5d430561f 100644 --- a/api/pkg/apis/v1alpha1/providers/target/kubectl/kubectl.go +++ b/api/pkg/apis/v1alpha1/providers/target/kubectl/kubectl.go @@ -125,7 +125,7 @@ func (i *KubectlTargetProvider) Init(config providers.IProviderConfig) error { updateConfig, err := toKubectlTargetProviderConfig(config) if err != nil { - sLog.Errorf(" P (Kubectl Target): expected KubectlTargetProviderConfig - %+v", err) + sLog.Errorf(" P (Kubectl Target): expected KubectlTargetProviderConfig - %+v") return err } @@ -150,7 +150,7 @@ func (i *KubectlTargetProvider) Init(config providers.IProviderConfig) error { if i.Config.ConfigData != "" { kConfig, err = clientcmd.RESTConfigFromKubeConfig([]byte(i.Config.ConfigData)) if err != nil { - sLog.Errorf(" P (Kubectl Target): %+v", err) + sLog.Errorf(" P (Kubectl Target): failed to get RESTconfg: %+v", err) return err } } else { @@ -165,25 +165,25 @@ func (i *KubectlTargetProvider) Init(config providers.IProviderConfig) error { } } if err != nil { - sLog.Errorf(" P (Kubectl Target): %+v", err) + sLog.Errorf(" P (Kubectl Target): failed to get the cluster config: %+v", err) return err } i.Client, err = kubernetes.NewForConfig(kConfig) if err != nil { - sLog.Errorf(" P (Kubectl Target): %+v", err) + sLog.Errorf(" P (Kubectl Target): failed to create a new clientset: %+v", err) return err } i.DynamicClient, err = dynamic.NewForConfig(kConfig) if err != nil { - sLog.Errorf(" P (Kubectl Target): %+v", err) + sLog.Errorf(" P (Kubectl Target): failed to create a dynamic client: %+v", err) return err } i.DiscoveryClient, err = discovery.NewDiscoveryClientForConfig(kConfig) if err != nil { - sLog.Errorf(" P (Kubectl Target): %+v", err) + sLog.Errorf(" P (Kubectl Target): failed to create a discovery client: %+v", err) return err } @@ -214,7 +214,7 @@ func (i *KubectlTargetProvider) Get(ctx context.Context, deployment model.Deploy ) var err error defer utils.CloseSpanWithError(span, &err) - sLog.Infof(" P (Kubectl Target): getting artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (Kubectl Target): getting artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) ret := make([]model.ComponentSpec, 0) for _, component := range references { @@ -226,17 +226,17 @@ func (i *KubectlTargetProvider) Get(ctx context.Context, deployment model.Deploy case dataBytes, ok := <-chanMes: if !ok { err = errors.New("failed to receive from data channel") - sLog.Error(" P (Kubectl Target): +%v", err) + sLog.Error(" P (Kubectl Target): +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } _, err = i.getCustomResource(ctx, dataBytes, deployment.Instance.Scope) if err != nil { if kerrors.IsNotFound(err) { - sLog.Infof(" P (Kubectl Target): resource not found: %s", err) + sLog.Infof(" P (Kubectl Target): resource not found: %s, traceId: %s", err, span.SpanContext().TraceID().String()) continue } - sLog.Error(" P (Kubectl Target): failed to read object: +%v", err) + sLog.Error(" P (Kubectl Target): failed to read object: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } @@ -246,14 +246,14 @@ func (i *KubectlTargetProvider) Get(ctx context.Context, deployment model.Deploy case err, ok := <-chanErr: if !ok { err = errors.New("failed to receive from error channel") - sLog.Error(" P (Kubectl Target): +%v", err) + sLog.Error(" P (Kubectl Target): +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } if err == io.EOF { stop = true } else { - sLog.Error(" P (Kubectl Target): failed to apply Yaml: +%v", err) + sLog.Error(" P (Kubectl Target): failed to apply Yaml: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } } @@ -262,17 +262,17 @@ func (i *KubectlTargetProvider) Get(ctx context.Context, deployment model.Deploy var dataBytes []byte dataBytes, err = json.Marshal(component.Component.Properties["resource"]) if err != nil { - sLog.Error(" P (Kubectl Target): failed to get deployment bytes from component: +%v", err) + sLog.Errorf(" P (Kubectl Target): failed to get deployment bytes from component: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } _, err = i.getCustomResource(ctx, dataBytes, deployment.Instance.Scope) if err != nil { if kerrors.IsNotFound(err) { - sLog.Infof(" P (Kubectl Target): resource not found: %s", err) + sLog.Infof(" P (Kubectl Target): resource not found: %v, traceId: %s", err, span.SpanContext().TraceID().String()) continue } - sLog.Error(" P (Kubectl Target): failed to read object: +%v", err) + sLog.Errorf(" P (Kubectl Target): failed to read object: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } @@ -280,7 +280,7 @@ func (i *KubectlTargetProvider) Get(ctx context.Context, deployment model.Deploy } else { err = errors.New("component doesn't have yaml or resource property") - sLog.Error(" P (Kubectl Target): component doesn't have yaml or resource property") + sLog.Errorf(" P (Kubectl Target): component doesn't have yaml or resource property, traceId: %s", span.SpanContext().TraceID().String()) return nil, err } } @@ -299,11 +299,12 @@ func (i *KubectlTargetProvider) Apply(ctx context.Context, deployment model.Depl ) var err error defer utils.CloseSpanWithError(span, &err) - sLog.Infof(" P (Kubectl Target): applying artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (Kubectl Target): applying artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) components := step.GetComponents() err = i.GetValidationRule(ctx).Validate(components) if err != nil { + sLog.Errorf(" P (Kubectl Target): failed to validate components, error: %v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } if isDryRun { @@ -323,28 +324,28 @@ func (i *KubectlTargetProvider) Apply(ctx context.Context, deployment model.Depl case dataBytes, ok := <-chanMes: if !ok { err = errors.New("failed to receive from data channel") - sLog.Error(" P (Kubectl Target): +%v", err) + sLog.Error(" P (Kubectl Target): +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } i.ensureNamespace(ctx, deployment.Instance.Scope) err = i.applyCustomResource(ctx, dataBytes, deployment.Instance.Scope) if err != nil { - sLog.Error(" P (Kubectl Target): failed to apply Yaml: +%v", err) + sLog.Error(" P (Kubectl Target): failed to apply Yaml: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } case err, ok := <-chanErr: if !ok { err = errors.New("failed to receive from error channel") - sLog.Error(" P (Kubectl Target): +%v", err) + sLog.Error(" P (Kubectl Target): +%v, traceId: %s, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } if err == io.EOF { stop = true } else { - sLog.Error(" P (Kubectl Target): failed to apply Yaml: +%v", err) + sLog.Error(" P (Kubectl Target): failed to apply Yaml: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } @@ -353,20 +354,20 @@ func (i *KubectlTargetProvider) Apply(ctx context.Context, deployment model.Depl var dataBytes []byte dataBytes, err = json.Marshal(component.Properties["resource"]) if err != nil { - sLog.Error(" P (Kubectl Target): failed to convert resource data to bytes: +%v", err) + sLog.Error(" P (Kubectl Target): failed to convert resource data to bytes: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } i.ensureNamespace(ctx, deployment.Instance.Scope) err = i.applyCustomResource(ctx, dataBytes, deployment.Instance.Scope) if err != nil { - sLog.Error(" P (Kubectl Target): failed to apply custom resource: +%v", err) + sLog.Error(" P (Kubectl Target): failed to apply custom resource: +%v, traceId: %s", err, err, span.SpanContext().TraceID().String()) return ret, err } } else { err = errors.New("component doesn't have yaml property or resource property") - sLog.Error(" P (Kubectl Target): component doesn't have yaml property or resource property") + sLog.Errorf(" P (Kubectl Target): component doesn't have yaml property or resource property, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } @@ -384,27 +385,27 @@ func (i *KubectlTargetProvider) Apply(ctx context.Context, deployment model.Depl case dataBytes, ok := <-chanMes: if !ok { err = errors.New("failed to receive from data channel") - sLog.Error(" P (Kubectl Target): +%v", err) + sLog.Errorf(" P (Kubectl Target): +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } err = i.deleteCustomResource(ctx, dataBytes, deployment.Instance.Scope) if err != nil { - sLog.Error(" P (Kubectl Target): failed to read object: +%v", err) + sLog.Errorf(" P (Kubectl Target): failed to read object: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } case err, ok := <-chanErr: if !ok { err = errors.New("failed to receive from error channel") - sLog.Error(" P (Kubectl Target): +%v", err) + sLog.Errorf(" P (Kubectl Target): +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } if err == io.EOF { stop = true } else { - sLog.Error(" P (Kubectl Target): failed to remove resource: +%v", err) + sLog.Errorf(" P (Kubectl Target): failed to remove resource: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } @@ -413,19 +414,19 @@ func (i *KubectlTargetProvider) Apply(ctx context.Context, deployment model.Depl var dataBytes []byte dataBytes, err = json.Marshal(component.Properties["resource"]) if err != nil { - sLog.Error(" P (Kubectl Target): failed to convert resource data to bytes: +%v", err) + sLog.Errorf(" P (Kubectl Target): failed to convert resource data to bytes: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } err = i.deleteCustomResource(ctx, dataBytes, deployment.Instance.Scope) if err != nil { - sLog.Error(" P (Kubectl Target): failed to delete custom resource: +%v", err) + sLog.Errorf(" P (Kubectl Target): failed to delete custom resource: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } else { err = errors.New("component doesn't have yaml property or resource property") - sLog.Error(" P (Kubectl Target): component doesn't have yaml property or resource property") + sLog.Errorf(" P (Kubectl Target): component doesn't have yaml property or resource property, traceId: %s", span.SpanContext().TraceID().String()) return ret, err } } @@ -445,6 +446,7 @@ func (k *KubectlTargetProvider) ensureNamespace(ctx context.Context, namespace s ) var err error defer utils.CloseSpanWithError(span, &err) + sLog.Infof(" P (Kubectl Target): ensureNamespace %s, traceId: %s", namespace, span.SpanContext().TraceID().String()) _, err = k.Client.CoreV1().Namespaces().Get(ctx, namespace, metav1.GetOptions{}) if err == nil { @@ -458,12 +460,12 @@ func (k *KubectlTargetProvider) ensureNamespace(ctx context.Context, namespace s }, }, metav1.CreateOptions{}) if err != nil { - sLog.Error("~~~ Kubectl Target Provider ~~~ : failed to create namespace: +%v", err) + sLog.Errorf(" P (Kubectl Target): failed to create namespace: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } } else { - sLog.Error("~~~ Kubectl Target Provider ~~~ : failed to get namespace: +%v", err) + sLog.Errorf(" P (Kubectl Target): failed to get namespace: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } diff --git a/api/pkg/apis/v1alpha1/providers/target/mqtt/mqtt.go b/api/pkg/apis/v1alpha1/providers/target/mqtt/mqtt.go index 5eab2ef25..8bf5d9875 100644 --- a/api/pkg/apis/v1alpha1/providers/target/mqtt/mqtt.go +++ b/api/pkg/apis/v1alpha1/providers/target/mqtt/mqtt.go @@ -178,7 +178,7 @@ func (i *MQTTTargetProvider) Init(config providers.IProviderConfig) error { var ret []model.ComponentSpec err = json.Unmarshal(response.Body, &ret) if err != nil { - sLog.Errorf(" P (MQTT Target): faild to deserialize components from MQTT - %+v, %s", err.Error(), string(response.Body)) + sLog.Errorf(" P (MQTT Target): faild to deserialize components from MQTT - %+v, %s", err, string(response.Body)) } proxyResponse.Payload = ret } @@ -218,7 +218,7 @@ func (i *MQTTTargetProvider) Get(ctx context.Context, deployment model.Deploymen }) var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Infof(" P (MQTT Target): getting artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (MQTT Target): getting artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) data, _ := json.Marshal(deployment) request := v1alpha2.COARequest{ @@ -232,7 +232,7 @@ func (i *MQTTTargetProvider) Get(ctx context.Context, deployment model.Deploymen data, _ = json.Marshal(request) if token := i.MQTTClient.Publish(i.Config.RequestTopic, 0, false, data); token.Wait() && token.Error() != nil { - sLog.Infof(" P (MQTT Target): failed to getting artifacts - %s", token.Error()) + sLog.Errorf(" P (MQTT Target): failed to getting artifacts - %s, traceId: %s", token.Error(), span.SpanContext().TraceID().String()) err = token.Error() return nil, err } @@ -244,24 +244,26 @@ func (i *MQTTTargetProvider) Get(ctx context.Context, deployment model.Deploymen var data []byte data, err = json.Marshal(resp.Payload) if err != nil { - sLog.Infof(" P (MQTT Target): failed to serialize payload - %s - %s", err.Error(), fmt.Sprint(resp.Payload)) + sLog.Errorf(" P (MQTT Target): failed to serialize payload - %s - %s, traceId: %s", err.Error(), fmt.Sprint(resp.Payload), span.SpanContext().TraceID().String()) err = v1alpha2.NewCOAError(nil, err.Error(), v1alpha2.InternalError) return nil, err } var ret []model.ComponentSpec err = json.Unmarshal(data, &ret) if err != nil { - sLog.Infof(" P (MQTT Target): failed to deserialize components - %s - %s", err.Error(), fmt.Sprint(data)) + sLog.Errorf(" P (MQTT Target): failed to deserialize components - %s - %s, traceId: %s", err.Error(), fmt.Sprint(data), span.SpanContext().TraceID().String()) err = v1alpha2.NewCOAError(nil, err.Error(), v1alpha2.InternalError) return nil, err } return ret, nil } else { err = v1alpha2.NewCOAError(nil, fmt.Sprint(resp.Payload), resp.State) + sLog.Errorf(" P (MQTT Target): failed to get response - %s - %s, traceId: %s", err.Error(), fmt.Sprint(data), span.SpanContext().TraceID().String()) return nil, err } case <-timeout: err = v1alpha2.NewCOAError(nil, "didn't get response to Get() call over MQTT", v1alpha2.InternalError) + sLog.Errorf(" P (MQTT Target): request timeout - %s - %s, traceId: %s", err.Error(), fmt.Sprint(data), span.SpanContext().TraceID().String()) return nil, err } } @@ -272,7 +274,7 @@ func (i *MQTTTargetProvider) Remove(ctx context.Context, deployment model.Deploy var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Infof(" P (MQTT Target): deleting artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (MQTT Target): deleting artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) data, _ := json.Marshal(deployment) request := v1alpha2.COARequest{ @@ -298,10 +300,12 @@ func (i *MQTTTargetProvider) Remove(ctx context.Context, deployment model.Deploy return err } else { err = v1alpha2.NewCOAError(nil, fmt.Sprint(resp.Payload), resp.State) + sLog.Errorf(" P (MQTT Target): failed to get correct response - %v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } case <-timeout: err = v1alpha2.NewCOAError(nil, "didn't get response to Remove() call over MQTT", v1alpha2.InternalError) + sLog.Errorf(" P (MQTT Target): request timeout - %v, traceId: %s", err, span.SpanContext().TraceID().String()) return err } } @@ -313,7 +317,7 @@ func (i *MQTTTargetProvider) Apply(ctx context.Context, deployment model.Deploym var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Infof(" P (MQTT Target): applying artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (MQTT Target): applying artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) components := step.GetComponents() err = i.GetValidationRule(ctx).Validate(components) @@ -354,10 +358,12 @@ func (i *MQTTTargetProvider) Apply(ctx context.Context, deployment model.Deploym return ret, err } else { err = v1alpha2.NewCOAError(nil, fmt.Sprint(resp.Payload), resp.State) + sLog.Errorf(" P (MQTT Target): failed to get correct response from Apply() - %v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } case <-timeout: - err = v1alpha2.NewCOAError(nil, "didn't get response to Apply() call over MQTT", v1alpha2.InternalError) + err = v1alpha2.NewCOAError(nil, "didn't get response to Apply()-Update call over MQTT", v1alpha2.InternalError) + sLog.Errorf(" P (MQTT Target): request timeout - %v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } @@ -386,10 +392,12 @@ func (i *MQTTTargetProvider) Apply(ctx context.Context, deployment model.Deploym return ret, err } else { err = v1alpha2.NewCOAError(nil, fmt.Sprint(resp.Payload), resp.State) + sLog.Errorf(" P (MQTT Target): failed to get correct reponse from Apply() delete action - %v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } case <-timeout: - err = v1alpha2.NewCOAError(nil, "didn't get response to Remove() call over MQTT", v1alpha2.InternalError) + err = v1alpha2.NewCOAError(nil, "didn't get response to Apply()-Delete call over MQTT", v1alpha2.InternalError) + sLog.Errorf(" P (MQTT Target): request timeout - %v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } diff --git a/api/pkg/apis/v1alpha1/providers/target/mqtt/mqtt_test.go b/api/pkg/apis/v1alpha1/providers/target/mqtt/mqtt_test.go index f34e503ca..4a5dfa2a3 100644 --- a/api/pkg/apis/v1alpha1/providers/target/mqtt/mqtt_test.go +++ b/api/pkg/apis/v1alpha1/providers/target/mqtt/mqtt_test.go @@ -21,13 +21,13 @@ import ( ) func TestDoubleIni(t *testing.T) { - testMQTT := os.Getenv("TEST_MQTT") + testMQTT := os.Getenv("TEST_MQTT_LOCAL_ENABLED") if testMQTT == "" { t.Skip("Skipping because TES_MQTT enviornment variable is not set") } config := MQTTTargetProviderConfig{ Name: "me", - BrokerAddress: "tcp://20.118.146.198:1883", + BrokerAddress: "tcp://127.0.0.1:1883", ClientID: "coa-test2", RequestTopic: "coa-request", ResponseTopic: "coa-response", @@ -40,13 +40,13 @@ func TestDoubleIni(t *testing.T) { } func TestInitWithMap(t *testing.T) { - testMQTT := os.Getenv("TEST_MQTT") + testMQTT := os.Getenv("TEST_MQTT_LOCAL_ENABLED") if testMQTT == "" { t.Skip("Skipping because TES_MQTT enviornment variable is not set") } configMap := map[string]string{ "name": "me", - "brokerAddress": "tcp://20.118.146.198:1883", + "brokerAddress": "tcp://127.0.0.1:1883", "clientID": "coa-test2", "requestTopic": "coa-request", "responseTopic": "coa-response", @@ -57,7 +57,7 @@ func TestInitWithMap(t *testing.T) { } func TestInitWithMapInvalidConfig(t *testing.T) { - testMQTT := os.Getenv("TEST_MQTT") + testMQTT := os.Getenv("TEST_MQTT_LOCAL_ENABLED") if testMQTT == "" { t.Skip("Skipping because TES_MQTT enviornment variable is not set") } @@ -70,14 +70,14 @@ func TestInitWithMapInvalidConfig(t *testing.T) { configMap = map[string]string{ "name": "me", - "brokerAddress": "tcp://20.118.146.198:1883", + "brokerAddress": "tcp://127.0.0.1:1883", } err = provider.InitWithMap(configMap) assert.NotNil(t, err) configMap = map[string]string{ "name": "me", - "brokerAddress": "tcp://20.118.146.198:1883", + "brokerAddress": "tcp://127.0.0.1:1883", "clientID": "coa-test2", } err = provider.InitWithMap(configMap) @@ -85,7 +85,7 @@ func TestInitWithMapInvalidConfig(t *testing.T) { configMap = map[string]string{ "name": "me", - "brokerAddress": "tcp://20.118.146.198:1883", + "brokerAddress": "tcp://127.0.0.1:1883", "clientID": "coa-test2", "requestTopic": "coa-request", } @@ -94,7 +94,7 @@ func TestInitWithMapInvalidConfig(t *testing.T) { configMap = map[string]string{ "name": "me", - "brokerAddress": "tcp://20.118.146.198:1883", + "brokerAddress": "tcp://127.0.0.1:1883", "clientID": "coa-test2", "requestTopic": "coa-request", "responseTopic": "coa-response", @@ -105,7 +105,7 @@ func TestInitWithMapInvalidConfig(t *testing.T) { configMap = map[string]string{ "name": "me", - "brokerAddress": "tcp://20.118.146.198:1883", + "brokerAddress": "tcp://127.0.0.1:1883", "clientID": "coa-test2", "requestTopic": "coa-request", "responseTopic": "coa-response", @@ -117,7 +117,7 @@ func TestInitWithMapInvalidConfig(t *testing.T) { configMap = map[string]string{ "name": "me", - "brokerAddress": "tcp://20.118.146.198:1883", + "brokerAddress": "tcp://127.0.0.1:1883", "clientID": "coa-test2", "requestTopic": "coa-request", "responseTopic": "coa-response", @@ -129,7 +129,7 @@ func TestInitWithMapInvalidConfig(t *testing.T) { configMap = map[string]string{ "name": "me", - "brokerAddress": "tcp://20.118.146.198:1883", + "brokerAddress": "tcp://127.0.0.1:1883", "clientID": "coa-test2", "requestTopic": "coa-request", "responseTopic": "coa-response", @@ -148,7 +148,7 @@ func TestGet(t *testing.T) { } config := MQTTTargetProviderConfig{ Name: "me", - BrokerAddress: "tcp://20.118.146.198:1883", + BrokerAddress: "tcp://127.0.0.1:1883", ClientID: "coa-test2", RequestTopic: "coa-request", ResponseTopic: "coa-response", @@ -240,7 +240,7 @@ func TestApply(t *testing.T) { } config := MQTTTargetProviderConfig{ Name: "me", - BrokerAddress: "tcp://20.118.146.198:1883", + BrokerAddress: "tcp://127.0.0.1:1883", ClientID: "coa-test2", RequestTopic: "coa-request", ResponseTopic: "coa-response", @@ -467,10 +467,67 @@ func TestGetApply(t *testing.T) { assert.Nil(t, err) } +func TestLocalApplyGet(t *testing.T) { + testMQTT := os.Getenv("TEST_MQTT_LOCAL_ENABLED") + if testMQTT == "" { + t.Skip("Skipping because TES_MQTT enviornment variable is not set") + } + config := MQTTTargetProviderConfig{ + Name: "me", + BrokerAddress: "tcp://127.0.0.1:1883", + ClientID: "coa-test2", + RequestTopic: "coa-request", + ResponseTopic: "coa-response", + TimeoutSeconds: 8, + } + provider := MQTTTargetProvider{} + err := provider.Init(config) + assert.Nil(t, err) + + opts := gmqtt.NewClientOptions().AddBroker(config.BrokerAddress).SetClientID("test-sender") + opts.SetKeepAlive(2 * time.Second) + opts.SetPingTimeout(1 * time.Second) + + c := gmqtt.NewClient(opts) + if token := c.Connect(); token.Wait() && token.Error() != nil { + panic(token.Error()) + } + if token := c.Subscribe(config.RequestTopic, 0, func(client gmqtt.Client, msg gmqtt.Message) { + var response v1alpha2.COAResponse + response.State = v1alpha2.OK + response.Metadata = make(map[string]string) + var request v1alpha2.COARequest + json.Unmarshal(msg.Payload(), &request) + if request.Method == "GET" { + response.Metadata["call-context"] = "TargetProvider-Get" + ret := make([]model.ComponentSpec, 0) + data, _ := json.Marshal(ret) + response.State = v1alpha2.OK + response.Body = data + } else { + response.Metadata["call-context"] = "TargetProvider-Apply" + response.State = v1alpha2.OK + } + data, _ := json.Marshal(response) + token := c.Publish(config.ResponseTopic, 0, false, data) + token.Wait() + }); token.Wait() && token.Error() != nil { + if token.Error().Error() != "subscription exists" { + panic(token.Error()) + } + } + + _, err = provider.Apply(context.Background(), model.DeploymentSpec{}, model.DeploymentStep{}, false) + assert.Nil(t, err) + arr, err := provider.Get(context.Background(), model.DeploymentSpec{}, nil) + assert.Nil(t, err) + assert.Equal(t, 0, len(arr)) +} + func TestInitFailed(t *testing.T) { config := MQTTTargetProviderConfig{ Name: "me", - BrokerAddress: "tcp://127.0.0.1:1883", + BrokerAddress: "tcp://8.8.8.8:1883", ClientID: "coa-test2", RequestTopic: "coa-request", ResponseTopic: "coa-response", diff --git a/api/pkg/apis/v1alpha1/providers/target/proxy/proxy.go b/api/pkg/apis/v1alpha1/providers/target/proxy/proxy.go index a52d2fe17..2283edec5 100644 --- a/api/pkg/apis/v1alpha1/providers/target/proxy/proxy.go +++ b/api/pkg/apis/v1alpha1/providers/target/proxy/proxy.go @@ -68,10 +68,11 @@ func (i *ProxyUpdateProvider) Init(config providers.IProviderConfig) error { }) var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Info("~~~ Proxy Provider ~~~ : Init()") + sLog.Info(" P (Proxy Target): Init()") updateConfig, err := toProxyUpdateProviderConfig(config) if err != nil { + sLog.Errorf(" P (Proxy Target): expected ProxyUpdateProviderConfig - %+v", err) err = errors.New("expected ProxyUpdateProviderConfig") return err } @@ -121,16 +122,18 @@ func (i *ProxyUpdateProvider) Get(ctx context.Context, deployment model.Deployme var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Infof("~~~ Proxy Provider ~~~ : getting artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (Proxy Target): getting artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) data, _ := json.Marshal(deployment) payload, err := i.callRestAPI("instances", "GET", data) if err != nil { + sLog.Error(" P (Proxy Target): failed to get instances: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } ret := make([]model.ComponentSpec, 0) err = json.Unmarshal(payload, &ret) if err != nil { + sLog.Error(" P (Proxy Target): failed to unmarshall get response: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } @@ -144,11 +147,12 @@ func (i *ProxyUpdateProvider) Apply(ctx context.Context, deployment model.Deploy var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Infof("~~~ Proxy Provider ~~~ : applying artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (Proxy Target): applying artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) components := step.GetComponents() err = i.GetValidationRule(ctx).Validate(components) if err != nil { + sLog.Errorf(" P (Proxy Target): failed to validate components: %v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } if isDryRun { @@ -163,9 +167,7 @@ func (i *ProxyUpdateProvider) Apply(ctx context.Context, deployment model.Deploy _, err = i.callRestAPI("instances", "POST", data) if err != nil { - return ret, err - } - if err != nil { + sLog.Error(" P (Proxy Target): failed to post instances: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } @@ -174,6 +176,7 @@ func (i *ProxyUpdateProvider) Apply(ctx context.Context, deployment model.Deploy data, _ := json.Marshal(deployment) _, err = i.callRestAPI("instances", "DELETE", data) if err != nil { + sLog.Error(" P (Proxy Target): failed to delete instances: +%v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } diff --git a/api/pkg/apis/v1alpha1/providers/target/script/script.go b/api/pkg/apis/v1alpha1/providers/target/script/script.go index de426bf46..736461d96 100644 --- a/api/pkg/apis/v1alpha1/providers/target/script/script.go +++ b/api/pkg/apis/v1alpha1/providers/target/script/script.go @@ -105,6 +105,7 @@ func (i *ScriptProvider) Init(config providers.IProviderConfig) error { updateConfig, err := toScriptProviderConfig(config) if err != nil { + sLog.Errorf(" P (Script Target): expected ScriptProviderConfig - %+v", err) err = errors.New("expected ScriptProviderConfig") return err } @@ -113,19 +114,21 @@ func (i *ScriptProvider) Init(config providers.IProviderConfig) error { if strings.HasPrefix(i.Config.ScriptFolder, "http") { err = downloadFile(i.Config.ScriptFolder, i.Config.ApplyScript, i.Config.StagingFolder) if err != nil { + sLog.Errorf(" P (Script Target): failed to download apply script %s, error: %+v", i.Config.ApplyScript, err) return err } err = downloadFile(i.Config.ScriptFolder, i.Config.RemoveScript, i.Config.StagingFolder) if err != nil { + sLog.Errorf(" P (Script Target): failed to download remove script %s, error: %+v", i.Config.RemoveScript, err) return err } err = downloadFile(i.Config.ScriptFolder, i.Config.GetScript, i.Config.StagingFolder) if err != nil { + sLog.Errorf(" P (Script Target): failed to download get script %s, error: %+v", i.Config.GetScript, err) return err } } - err = nil return nil } func downloadFile(scriptFolder string, script string, stagingFolder string) error { @@ -169,7 +172,7 @@ func (i *ScriptProvider) Get(ctx context.Context, deployment model.DeploymentSpe var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Infof(" P (Script Target): getting artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (Script Target): getting artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) id := uuid.New().String() input := id + ".json" @@ -196,10 +199,10 @@ func (i *ScriptProvider) Get(ctx context.Context, deployment model.DeploymentSpe } o, err := i.runCommand(scriptAbs, abs, abs_ref) - sLog.Debugf(" P (Script Target): get script output: %s", o) + sLog.Debugf(" P (Script Target): get script output: %s, traceId: %s", o, span.SpanContext().TraceID().String()) if err != nil { - sLog.Errorf(" P (Script Target): failed to run get script: %+v", err) + sLog.Errorf(" P (Script Target): failed to run get script: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } @@ -208,7 +211,7 @@ func (i *ScriptProvider) Get(ctx context.Context, deployment model.DeploymentSpe data, err := ioutil.ReadFile(outputStaging) if err != nil { - sLog.Errorf(" P (Script Target): failed to parse get script output (expected []ComponentSpec): %+v", err) + sLog.Errorf(" P (Script Target): failed to read output file: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } @@ -219,7 +222,7 @@ func (i *ScriptProvider) Get(ctx context.Context, deployment model.DeploymentSpe ret := make([]model.ComponentSpec, 0) err = json.Unmarshal(data, &ret) if err != nil { - sLog.Errorf(" P (Script Target): failed to parse get script output (expected []ComponentSpec): %+v", err) + sLog.Errorf(" P (Script Target): failed to parse get script output (expected []ComponentSpec): %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } return ret, nil @@ -269,7 +272,7 @@ func (i *ScriptProvider) runScriptOnComponents(deployment model.DeploymentSpec, data, err := ioutil.ReadFile(outputStaging) if err != nil { - sLog.Errorf(" P (Script Target): failed to parse apply script output (expected map[string]model.ComponentResultSpec): %+v", err) + sLog.Errorf(" P (Script Target): failed to pread output file: %+v", err) return nil, err } @@ -291,7 +294,7 @@ func (i *ScriptProvider) Apply(ctx context.Context, deployment model.DeploymentS }) var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Infof(" P (Script Target): applying artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (Script Target): applying artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) err = i.GetValidationRule(ctx).Validate([]model.ComponentSpec{}) //this provider doesn't handle any components TODO: is this right? if err != nil { @@ -308,7 +311,7 @@ func (i *ScriptProvider) Apply(ctx context.Context, deployment model.DeploymentS var retU map[string]model.ComponentResultSpec retU, err = i.runScriptOnComponents(deployment, components, false) if err != nil { - sLog.Errorf(" P (Script Target): failed to run apply script: %+v", err) + sLog.Errorf(" P (Script Target): failed to run apply script: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } for k, v := range retU { @@ -320,7 +323,7 @@ func (i *ScriptProvider) Apply(ctx context.Context, deployment model.DeploymentS var retU map[string]model.ComponentResultSpec retU, err = i.runScriptOnComponents(deployment, components, true) if err != nil { - sLog.Errorf(" P (Script Target): failed to run remove script: %+v", err) + sLog.Errorf(" P (Script Target): failed to run remove script: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } for k, v := range retU { diff --git a/api/pkg/apis/v1alpha1/providers/target/staging/staging.go b/api/pkg/apis/v1alpha1/providers/target/staging/staging.go index 8d26483d2..1c54edf99 100644 --- a/api/pkg/apis/v1alpha1/providers/target/staging/staging.go +++ b/api/pkg/apis/v1alpha1/providers/target/staging/staging.go @@ -86,7 +86,7 @@ func (i *StagingTargetProvider) Get(ctx context.Context, deployment model.Deploy ctx, span := observability.StartSpan("Staging Target Provider", ctx, &map[string]string{ "method": "Get", }) - sLog.Infof(" P (Staging Target): getting artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (Staging Target): getting artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) var err error defer observ_utils.CloseSpanWithError(span, &err) @@ -104,10 +104,10 @@ func (i *StagingTargetProvider) Get(ctx context.Context, deployment model.Deploy if err != nil { if v1alpha2.IsNotFound(err) { - sLog.Infof(" P (Staging Target): no staged artifact found") + sLog.Infof(" P (Staging Target): no staged artifact found, traceId: %s") return nil, nil } - sLog.Errorf(" P (Staging Target): failed to get staged artifact: %v", err) + sLog.Errorf(" P (Staging Target): failed to get staged artifact: %v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } @@ -116,7 +116,7 @@ func (i *StagingTargetProvider) Get(ctx context.Context, deployment model.Deploy jData, _ := json.Marshal(spec) err = json.Unmarshal(jData, &components) if err != nil { - sLog.Errorf(" P (Staging Target): failed to get staged artifact: %v", err) + sLog.Errorf(" P (Staging Target): failed to get staged artifact: %v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } ret := make([]model.ComponentSpec, len(references)) @@ -131,21 +131,21 @@ func (i *StagingTargetProvider) Get(ctx context.Context, deployment model.Deploy return ret, nil } err = v1alpha2.NewCOAError(nil, "staged artifact is not found as a 'spec' property", v1alpha2.NotFound) - sLog.Errorf(" P (Staging Target): failed to get staged artifact: %v", err) + sLog.Errorf(" P (Staging Target): failed to get staged artifact: %v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } func (i *StagingTargetProvider) Apply(ctx context.Context, deployment model.DeploymentSpec, step model.DeploymentStep, isDryRun bool) (map[string]model.ComponentResultSpec, error) { ctx, span := observability.StartSpan("Staging Target Provider", ctx, &map[string]string{ "method": "Apply", }) - sLog.Infof(" P (Staging Target): applying artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (Staging Target): applying artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) var err error defer observ_utils.CloseSpanWithError(span, &err) err = i.GetValidationRule(ctx).Validate([]model.ComponentSpec{}) //this provider doesn't handle any components TODO: is this right? if err != nil { - sLog.Errorf(" P (Staging Target): failed to validate components: %v", err) + sLog.Errorf(" P (Staging Target): failed to validate components: %v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } if isDryRun { @@ -168,7 +168,7 @@ func (i *StagingTargetProvider) Apply(ctx context.Context, deployment model.Depl i.Context.SiteInfo.CurrentSite.Username, i.Context.SiteInfo.CurrentSite.Password) if err != nil && !v1alpha2.IsNotFound(err) { - sLog.Errorf(" P (Staging Target): failed to get staged artifact: %v", err) + sLog.Errorf(" P (Staging Target): failed to get staged artifact: %v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } @@ -189,7 +189,7 @@ func (i *StagingTargetProvider) Apply(ctx context.Context, deployment model.Depl jData, _ := json.Marshal(v) err = json.Unmarshal(jData, &existing) if err != nil { - sLog.Errorf(" P (Staging Target): failed to get staged artifact: %v", err) + sLog.Errorf(" P (Staging Target): failed to unmarshall catalog components: %v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } @@ -220,7 +220,7 @@ func (i *StagingTargetProvider) Apply(ctx context.Context, deployment model.Depl jData, _ := json.Marshal(v) err = json.Unmarshal(jData, &deleted) if err != nil { - sLog.Errorf(" P (Staging Target): failed to get staged artifact: %v", err) + sLog.Errorf(" P (Staging Target): failed to get staged artifact: %v, traceId: %s", err, span.SpanContext().TraceID().String()) return ret, err } } @@ -256,7 +256,7 @@ func (i *StagingTargetProvider) Apply(ctx context.Context, deployment model.Depl i.Context.SiteInfo.CurrentSite.Username, i.Context.SiteInfo.CurrentSite.Password, jData) if err != nil { - sLog.Errorf(" P (Staging Target): failed to upsert staged artifact: %v", err) + sLog.Errorf(" P (Staging Target): failed to upsert staged artifact: %v, traceId: %s", err, span.SpanContext().TraceID().String()) } 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 3b18ca03f..91ec5a35d 100644 --- a/api/pkg/apis/v1alpha1/providers/target/win10/sideload/sideload.go +++ b/api/pkg/apis/v1alpha1/providers/target/win10/sideload/sideload.go @@ -94,10 +94,11 @@ func (i *Win10SideLoadProvider) Init(config providers.IProviderConfig) error { var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Info("~~~ Win 10 Sideload Provider ~~~ : Init()") + sLog.Info(" P (Win10Sideload Target): Init()") updateConfig, err := toWin10SideLoadProviderConfig(config) if err != nil { + sLog.Errorf(" P (Win10Sideload Target): expected Win10SideLoadProviderConfig - %+v", err) err = errors.New("expected Win10SideLoadProviderConfig") return err } @@ -121,7 +122,7 @@ func (i *Win10SideLoadProvider) Get(ctx context.Context, deployment model.Deploy var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Infof("~~~ Win 10 Sideload Provider ~~~ : getting artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (Win10Sideload Target): getting artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) params := make([]string, 0) params = append(params, "list") @@ -135,6 +136,7 @@ func (i *Win10SideLoadProvider) Get(ctx context.Context, deployment model.Deploy out, err := exec.Command(i.Config.WinAppDeployCmdPath, params...).Output() if err != nil { + sLog.Errorf(" P (Win10Sideload Target): failed to run deploy cmd %s, error: %+v, traceId: %s", i.Config.WinAppDeployCmdPath, err, span.SpanContext().TraceID().String()) return nil, err } str := string(out) @@ -170,11 +172,12 @@ func (i *Win10SideLoadProvider) Apply(ctx context.Context, deployment model.Depl var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Infof("~~~ Win 10 Sideload Provider ~~~ : applying artifacts: %s - %s", deployment.Instance.Scope, deployment.Instance.Name) + sLog.Infof(" P (Win10Sideload Target): applying artifacts: %s - %s, traceId: %s", deployment.Instance.Scope, deployment.Instance.Name, span.SpanContext().TraceID().String()) components := step.GetComponents() err = i.GetValidationRule(ctx).Validate(components) if err != nil { + sLog.Errorf(" P (Win10Sideload Target): failed to validate components, error: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return nil, err } if isDryRun { @@ -201,6 +204,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.Errorf(" P (Win10Sideload Target): failed to install application %s, error: %+v, traceId: %s", path, err, span.SpanContext().TraceID().String()) ret[component.Name] = model.ComponentResultSpec{ Status: v1alpha2.UpdateFailed, Message: err.Error(), @@ -243,6 +247,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.Errorf(" P (Win10Sideload Target): failed to uninstall application %s, error: %+v, traceId: %s", name, err, span.SpanContext().TraceID().String()) if i.Config.Silent { return ret, nil } else { diff --git a/api/pkg/apis/v1alpha1/vendors/agent-vendor.go b/api/pkg/apis/v1alpha1/vendors/agent-vendor.go index 277869ca7..71133a61d 100644 --- a/api/pkg/apis/v1alpha1/vendors/agent-vendor.go +++ b/api/pkg/apis/v1alpha1/vendors/agent-vendor.go @@ -81,7 +81,7 @@ func (c *AgentVendor) onConfig(request v1alpha2.COARequest) v1alpha2.COAResponse }) defer span.End() - log.Infof("V (Agent): onConfig %s", request.Method) + log.Infof("V (Agent): onConfig %s, traceId: %s", request.Method, span.SpanContext().TraceID().String()) switch request.Method { case fasthttp.MethodPost: @@ -104,7 +104,7 @@ func (c *AgentVendor) onReference(request v1alpha2.COARequest) v1alpha2.COARespo }) defer span.End() - log.Infof("V (Agent): onReference %s", request.Method) + log.Infof("V (Agent): onReference %s, traceId: %s", request.Method, span.SpanContext().TraceID().String()) switch request.Method { case fasthttp.MethodGet: @@ -117,6 +117,7 @@ func (c *AgentVendor) onReference(request v1alpha2.COARequest) v1alpha2.COARespo return observ_utils.CloseSpanWithCOAResponse(span, response) } + log.Infof("V (Agent): onReference returns MethodNotAllowed, traceId: %s", span.SpanContext().TraceID().String()) resp := v1alpha2.COAResponse{ State: v1alpha2.MethodNotAllowed, Body: []byte("{\"result\":\"405 - method not allowed\"}"), @@ -127,6 +128,12 @@ func (c *AgentVendor) onReference(request v1alpha2.COARequest) v1alpha2.COARespo } func (c *AgentVendor) doGet(ctx context.Context, parameters map[string]string) v1alpha2.COAResponse { + _, span := observability.StartSpan("Agent Vendor", ctx, &map[string]string{ + "method": "doGet", + }) + defer span.End() + log.Infof("V (Agent): doGet with parameters %v, traceId: %s", parameters, span.SpanContext().TraceID().String()) + var scope = "default" var kind = "" var ref = "" @@ -194,11 +201,14 @@ func (c *AgentVendor) doGet(ctx context.Context, parameters map[string]string) v data, err = c.ReferenceManager.Get(ref, id, scope, group, kind, version, labelSelector, fieldSelector) } if err != nil { + log.Errorf("V (Agent): failed to get references, traceId: %s", span.SpanContext().TraceID().String()) return v1alpha2.COAResponse{ State: v1alpha2.InternalError, Body: []byte(err.Error()), } } + + log.Info("V (Agent): get references successfully") return v1alpha2.COAResponse{ State: v1alpha2.OK, Body: data, @@ -207,6 +217,13 @@ func (c *AgentVendor) doGet(ctx context.Context, parameters map[string]string) v } func (c *AgentVendor) doApplyConfig(ctx context.Context, parameters map[string]string, data []byte) v1alpha2.COAResponse { + _, span := observability.StartSpan("Agent Vendor", ctx, &map[string]string{ + "method": "doApplyConfig", + }) + defer span.End() + + log.Infof("V (Agent): doApplyConfig with parameters %v, traceId: %s", parameters, span.SpanContext().TraceID().String()) + var config managers.ProviderConfig err := json.Unmarshal(data, &config) if err != nil { @@ -229,6 +246,8 @@ func (c *AgentVendor) doApplyConfig(ctx context.Context, parameters map[string]s } } } + + log.Info("V (Agent): apply configs successfully") return v1alpha2.COAResponse{ State: v1alpha2.OK, Body: []byte("{}"), @@ -237,6 +256,13 @@ func (c *AgentVendor) doApplyConfig(ctx context.Context, parameters map[string]s } func (c *AgentVendor) doPost(ctx context.Context, parameters map[string]string, data []byte) v1alpha2.COAResponse { + _, span := observability.StartSpan("Agent Vendor", ctx, &map[string]string{ + "method": "doPost", + }) + defer span.End() + + log.Infof("V (Agent): doPost with parameters %v, traceId: %s", parameters, span.SpanContext().TraceID().String()) + var scope = "default" var kind = "" var group = "" @@ -264,6 +290,7 @@ func (c *AgentVendor) doPost(ctx context.Context, parameters map[string]string, properties := make(map[string]string) err := json.Unmarshal(data, &properties) if err != nil { + log.Errorf("V (Agent): failed to unmarshall data, traceId: %s", span.SpanContext().TraceID().String()) return v1alpha2.COAResponse{ State: v1alpha2.InternalError, Body: []byte(err.Error()), @@ -271,11 +298,14 @@ func (c *AgentVendor) doPost(ctx context.Context, parameters map[string]string, } err = c.ReferenceManager.Report(id, scope, group, kind, version, properties, overwrite) if err != nil { + log.Errorf("V (Agent): failed to report status, traceId: %s", span.SpanContext().TraceID().String()) return v1alpha2.COAResponse{ State: v1alpha2.InternalError, Body: []byte(err.Error()), } } + + log.Info("V (Agent): report status successfully") return v1alpha2.COAResponse{ State: v1alpha2.OK, Body: data, diff --git a/api/pkg/apis/v1alpha1/vendors/devices-vendor.go b/api/pkg/apis/v1alpha1/vendors/devices-vendor.go index 9a34ad79d..4a54fd355 100644 --- a/api/pkg/apis/v1alpha1/vendors/devices-vendor.go +++ b/api/pkg/apis/v1alpha1/vendors/devices-vendor.go @@ -75,8 +75,7 @@ func (c *DevicesVendor) onDevices(request v1alpha2.COARequest) v1alpha2.COARespo "method": "onDevices", }) defer span.End() - - tLog.Info("~ Devices Manager ~ : onDevices") + tLog.Infof("V (Devices): onDevices %s, traceId: %s", request.Method, span.SpanContext().TraceID().String()) switch request.Method { case fasthttp.MethodGet: @@ -92,6 +91,7 @@ func (c *DevicesVendor) onDevices(request v1alpha2.COARequest) v1alpha2.COARespo state, err = c.DevicesManager.GetSpec(ctx, id) } if err != nil { + log.Errorf("V (Devices): failed to get device spec, error %v, traceId: %s", err, span.SpanContext().TraceID().String()) return observ_utils.CloseSpanWithCOAResponse(span, v1alpha2.COAResponse{ State: v1alpha2.InternalError, Body: []byte(err.Error()), @@ -115,6 +115,7 @@ func (c *DevicesVendor) onDevices(request v1alpha2.COARequest) v1alpha2.COARespo err := json.Unmarshal(request.Body, &device) if err != nil { + log.Errorf("V (Devices): failed to unmarshall request body, error %v, traceId: %s", err, span.SpanContext().TraceID().String()) return observ_utils.CloseSpanWithCOAResponse(span, v1alpha2.COAResponse{ State: v1alpha2.InternalError, Body: []byte(err.Error()), @@ -123,6 +124,7 @@ func (c *DevicesVendor) onDevices(request v1alpha2.COARequest) v1alpha2.COARespo err = c.DevicesManager.UpsertSpec(ctx, id, device) if err != nil { + log.Errorf("V (Devices): failed to upsert device spec, error %v, traceId: %s", err, span.SpanContext().TraceID().String()) return observ_utils.CloseSpanWithCOAResponse(span, v1alpha2.COAResponse{ State: v1alpha2.InternalError, Body: []byte(err.Error()), @@ -136,6 +138,7 @@ func (c *DevicesVendor) onDevices(request v1alpha2.COARequest) v1alpha2.COARespo id := request.Parameters["__name"] err := c.DevicesManager.DeleteSpec(ctx, id) if err != nil { + log.Errorf("V (Devices): failed to delete device spec, error %v, traceId: %s", err, span.SpanContext().TraceID().String()) return observ_utils.CloseSpanWithCOAResponse(span, v1alpha2.COAResponse{ State: v1alpha2.InternalError, Body: []byte(err.Error()), @@ -145,6 +148,8 @@ func (c *DevicesVendor) onDevices(request v1alpha2.COARequest) v1alpha2.COARespo State: v1alpha2.OK, }) } + + log.Infof("V (Devices): onDevices returns MethodNotAllowed, traceId: %s", span.SpanContext().TraceID().String()) resp := v1alpha2.COAResponse{ State: v1alpha2.MethodNotAllowed, Body: []byte("{\"result\":\"405 - method not allowed\"}"), diff --git a/api/pkg/apis/v1alpha1/vendors/settings-vendor.go b/api/pkg/apis/v1alpha1/vendors/settings-vendor.go index a0e156869..0e2cdf0ba 100644 --- a/api/pkg/apis/v1alpha1/vendors/settings-vendor.go +++ b/api/pkg/apis/v1alpha1/vendors/settings-vendor.go @@ -78,7 +78,8 @@ func (c *SettingsVendor) onConfig(request v1alpha2.COARequest) v1alpha2.COARespo "method": "onConfig", }) defer span.End() - csLog.Info("V (Settings): onConfig") + csLog.Infof("V (Settings): onConfig %s, traceId: %s", request.Method, span.SpanContext().TraceID().String()) + switch request.Method { case fasthttp.MethodGet: id := request.Parameters["__name"] @@ -91,6 +92,7 @@ func (c *SettingsVendor) onConfig(request v1alpha2.COARequest) v1alpha2.COARespo if field != "" { val, err := c.EvaluationContext.ConfigProvider.Get(id, field, parts, nil) if err != nil { + log.Errorf("V (Settings): onConfig failed to get config %s, error: %v traceId: %s", id, err, span.SpanContext().TraceID().String()) return observ_utils.CloseSpanWithCOAResponse(span, v1alpha2.COAResponse{ State: v1alpha2.InternalError, Body: []byte(err.Error()), @@ -105,6 +107,7 @@ func (c *SettingsVendor) onConfig(request v1alpha2.COARequest) v1alpha2.COARespo } else { val, err := c.EvaluationContext.ConfigProvider.GetObject(id, parts, nil) if err != nil { + log.Errorf("V (Settings): onConfig failed to get object %s, error: %v traceId: %s", id, err, span.SpanContext().TraceID().String()) return observ_utils.CloseSpanWithCOAResponse(span, v1alpha2.COAResponse{ State: v1alpha2.InternalError, Body: []byte(err.Error()), @@ -118,6 +121,8 @@ func (c *SettingsVendor) onConfig(request v1alpha2.COARequest) v1alpha2.COARespo }) } } + + log.Infof("V (Settings): onConfig returned MethodNotAllowed, traceId: %s", span.SpanContext().TraceID().String()) resp := v1alpha2.COAResponse{ State: v1alpha2.MethodNotAllowed, Body: []byte("{\"result\":\"405 - method not allowed\"}"), diff --git a/api/pkg/apis/v1alpha1/vendors/targets-vendor.go b/api/pkg/apis/v1alpha1/vendors/targets-vendor.go index 02d2eca46..2c8b7c534 100644 --- a/api/pkg/apis/v1alpha1/vendors/targets-vendor.go +++ b/api/pkg/apis/v1alpha1/vendors/targets-vendor.go @@ -114,7 +114,8 @@ func (c *TargetsVendor) onRegistry(request v1alpha2.COARequest) v1alpha2.COAResp "method": "onRegistry", }) defer span.End() - tLog.Info("V (Targets) : onRegistry") + log.Infof("V (Targets): onRegistry %s, traceId: %s", request.Method, span.SpanContext().TraceID().String()) + scope, exist := request.Parameters["scope"] if !exist { scope = "default" @@ -159,6 +160,7 @@ func (c *TargetsVendor) onRegistry(request v1alpha2.COARequest) v1alpha2.COAResp var target model.TargetSpec err := json.Unmarshal(request.Body, &target) if err != nil { + log.Errorf("V (Targets): onRegistry failed to unmarshall request body, error: %v traceId: %s", err, span.SpanContext().TraceID().String()) return observ_utils.CloseSpanWithCOAResponse(span, v1alpha2.COAResponse{ State: v1alpha2.InternalError, Body: []byte(err.Error()), @@ -207,6 +209,7 @@ func (c *TargetsVendor) onRegistry(request v1alpha2.COARequest) v1alpha2.COAResp } err = c.TargetsManager.UpsertSpec(ctx, id, scope, target) if err != nil { + log.Errorf("V (Targets): onRegistry failed to upsert spec, error: %v traceId: %s", err, span.SpanContext().TraceID().String()) return observ_utils.CloseSpanWithCOAResponse(span, v1alpha2.COAResponse{ State: v1alpha2.InternalError, Body: []byte(err.Error()), @@ -249,6 +252,7 @@ func (c *TargetsVendor) onRegistry(request v1alpha2.COARequest) v1alpha2.COAResp } else { err := c.TargetsManager.DeleteSpec(ctx, id, scope) if err != nil { + log.Errorf("V (Targets): onRegistry failed to delete spec, error: %v traceId: %s", err, span.SpanContext().TraceID().String()) return observ_utils.CloseSpanWithCOAResponse(span, v1alpha2.COAResponse{ State: v1alpha2.InternalError, Body: []byte(err.Error()), @@ -259,6 +263,8 @@ func (c *TargetsVendor) onRegistry(request v1alpha2.COARequest) v1alpha2.COAResp State: v1alpha2.OK, }) } + + log.Infof("V (Targets): onRegistry returned MethodNotAllowed, traceId: %s", span.SpanContext().TraceID().String()) resp := v1alpha2.COAResponse{ State: v1alpha2.MethodNotAllowed, Body: []byte("{\"result\":\"405 - method not allowed\"}"), @@ -273,10 +279,12 @@ func (c *TargetsVendor) onBootstrap(request v1alpha2.COARequest) v1alpha2.COARes "method": "onBootstrap", }) defer span.End() + log.Infof("V (Targets): onBootstrap %s, traceId: %s", request.Method, span.SpanContext().TraceID().String()) var authRequest AuthRequest err := json.Unmarshal(request.Body, &authRequest) if err != nil || authRequest.UserName != "symphony-test" { + log.Error("V (Targets): onBootstrap returned Unauthorized, traceId: %s", request.Method, span.SpanContext().TraceID().String()) return observ_utils.CloseSpanWithCOAResponse(span, v1alpha2.COAResponse{ State: v1alpha2.Unauthorized, Body: []byte(err.Error()), @@ -300,6 +308,7 @@ func (c *TargetsVendor) onBootstrap(request v1alpha2.COARequest) v1alpha2.COARes token := jwt.NewWithClaims(jwt.SigningMethodHS256, claims) ss, _ := token.SignedString(mySigningKey) + log.Info("V (Targets): onBootstrap succeeded, traceId: %s", span.SpanContext().TraceID().String()) resp := v1alpha2.COAResponse{ State: v1alpha2.OK, Body: []byte(`{"accessToken":"` + ss + `", "tokenType": "Bearer"}`), @@ -314,6 +323,8 @@ func (c *TargetsVendor) onStatus(request v1alpha2.COARequest) v1alpha2.COARespon "method": "onStatus", }) defer span.End() + log.Infof("V (Targets): onStatus %s, traceId: %s", request.Method, span.SpanContext().TraceID().String()) + scope, exist := request.Parameters["scope"] if !exist { scope = "default" @@ -350,12 +361,15 @@ func (c *TargetsVendor) onStatus(request v1alpha2.COARequest) v1alpha2.COARespon }) if err != nil { + log.Errorf("V (Targets): onStatus failed to report state, error: %v traceId: %s", err, span.SpanContext().TraceID().String()) return observ_utils.CloseSpanWithCOAResponse(span, v1alpha2.COAResponse{ State: v1alpha2.InternalError, Body: []byte(err.Error()), }) } jData, _ := json.Marshal(state) + + log.Info("V (Targets): onStatus succeeded, traceId: %s", span.SpanContext().TraceID().String()) resp := v1alpha2.COAResponse{ State: v1alpha2.OK, Body: jData, @@ -370,12 +384,15 @@ func (c *TargetsVendor) onDownload(request v1alpha2.COARequest) v1alpha2.COAResp "method": "onDownload", }) defer span.End() + log.Infof("V (Targets): onDownload %s, traceId: %s", request.Method, span.SpanContext().TraceID().String()) + scope, exist := request.Parameters["scope"] if !exist { scope = "default" } state, err := c.TargetsManager.GetSpec(pCtx, request.Parameters["__name"], scope) if err != nil { + log.Errorf("V (Targets): onDownload failed to get target spec, error: %v traceId: %s", err, span.SpanContext().TraceID().String()) return observ_utils.CloseSpanWithCOAResponse(span, v1alpha2.COAResponse{ State: v1alpha2.InternalError, Body: []byte(err.Error()), @@ -383,6 +400,7 @@ func (c *TargetsVendor) onDownload(request v1alpha2.COARequest) v1alpha2.COAResp } jData, err := utils.FormatObject(state, false, request.Parameters["path"], request.Parameters["__doc-type"]) if err != nil { + log.Errorf("V (Targets): onDownload failed to format target object, error: %v traceId: %s", err, span.SpanContext().TraceID().String()) return observ_utils.CloseSpanWithCOAResponse(span, v1alpha2.COAResponse{ State: v1alpha2.InternalError, Body: []byte(err.Error()), @@ -398,6 +416,7 @@ func (c *TargetsVendor) onDownload(request v1alpha2.COARequest) v1alpha2.COAResp resp.ContentType = "application/text" } + log.Info("V (Targets): onDownload succeeded, traceId: %s", span.SpanContext().TraceID().String()) observ_utils.UpdateSpanStatusFromCOAResponse(span, resp) return resp } @@ -407,6 +426,8 @@ func (c *TargetsVendor) onHeartBeat(request v1alpha2.COARequest) v1alpha2.COARes "method": "onHeartBeat", }) defer span.End() + log.Infof("V (Targets): onHeartBeat %s, traceId: %s", request.Method, span.SpanContext().TraceID().String()) + scope, exist := request.Parameters["scope"] if !exist { scope = "default" @@ -425,12 +446,14 @@ func (c *TargetsVendor) onHeartBeat(request v1alpha2.COARequest) v1alpha2.COARes }) if err != nil { + log.Errorf("V (Targets): failed to report state, error: %v traceId: %s", err, span.SpanContext().TraceID().String()) return observ_utils.CloseSpanWithCOAResponse(span, v1alpha2.COAResponse{ State: v1alpha2.InternalError, Body: []byte(err.Error()), }) } + log.Info("V (Targets): onHeartBeat succeeded, traceId: %s", span.SpanContext().TraceID().String()) resp := v1alpha2.COAResponse{ State: v1alpha2.OK, Body: []byte(`{}`), diff --git a/api/pkg/apis/v1alpha1/vendors/users-vendor.go b/api/pkg/apis/v1alpha1/vendors/users-vendor.go index 6c5311d03..e5f3d4653 100644 --- a/api/pkg/apis/v1alpha1/vendors/users-vendor.go +++ b/api/pkg/apis/v1alpha1/vendors/users-vendor.go @@ -84,11 +84,12 @@ func (c *UsersVendor) onAuth(request v1alpha2.COARequest) v1alpha2.COAResponse { "method": "onAuth", }) defer span.End() - log.Debug("V (Users): authenticate user") + log.Infof("V (Users): authenticate user %s, traceId: %s", request.Method, span.SpanContext().TraceID().String()) var authRequest AuthRequest err := json.Unmarshal(request.Body, &authRequest) if err != nil { + log.Errorf("V (Targets): onAuth failed to unmarshall request body, error: %v traceId: %s", err, span.SpanContext().TraceID().String()) return observ_utils.CloseSpanWithCOAResponse(span, v1alpha2.COAResponse{ State: v1alpha2.Unauthorized, Body: []byte(err.Error()), @@ -120,6 +121,7 @@ func (c *UsersVendor) onAuth(request v1alpha2.COARequest) v1alpha2.COAResponse { token := jwt.NewWithClaims(jwt.SigningMethodHS256, claims) ss, _ := token.SignedString(mySigningKey) + log.Infof("V (Targets): onAuth succeeded, traceId: %s", span.SpanContext().TraceID().String()) rolesJSON, _ := json.Marshal(roles) resp := v1alpha2.COAResponse{ State: v1alpha2.OK, diff --git a/coa/pkg/apis/v1alpha2/bindings/mqtt/mqtt_test.go b/coa/pkg/apis/v1alpha2/bindings/mqtt/mqtt_test.go index 282ef2cca..b2cc233ec 100644 --- a/coa/pkg/apis/v1alpha2/bindings/mqtt/mqtt_test.go +++ b/coa/pkg/apis/v1alpha2/bindings/mqtt/mqtt_test.go @@ -18,13 +18,13 @@ import ( ) func TestMQTTEcho(t *testing.T) { - testMQTT := os.Getenv("TEST_MQTT") + testMQTT := os.Getenv("TEST_MQTT_LOCAL_ENABLED") if testMQTT == "" { t.Skip("Skipping because TES_MQTT enviornment variable is not set") } sig := make(chan int) config := MQTTBindingConfig{ - BrokerAddress: "tcp://20.118.146.198:1883", + BrokerAddress: "tcp://127.0.0.1:1883", ClientID: "coa-test2", RequestTopic: "coa-request", ResponseTopic: "coa-response", diff --git a/coa/pkg/apis/v1alpha2/providers/certs/autogen/autogen.go b/coa/pkg/apis/v1alpha2/providers/certs/autogen/autogen.go index 8876fcf9e..36574f9fa 100644 --- a/coa/pkg/apis/v1alpha2/providers/certs/autogen/autogen.go +++ b/coa/pkg/apis/v1alpha2/providers/certs/autogen/autogen.go @@ -12,9 +12,12 @@ import ( "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2" "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/contexts" "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/providers" + "github.com/eclipse-symphony/symphony/coa/pkg/logger" fasthttp "github.com/valyala/fasthttp" ) +var log = logger.NewLogger("coa.runtime") + type AutoGenCertProviderConfig struct { Name string `json:"name"` } @@ -31,6 +34,7 @@ func (s *AutoGenCertProvider) SetContext(ctx contexts.ManagerContext) { func (w *AutoGenCertProvider) Init(config providers.IProviderConfig) error { certConfig, err := toAutoGenCertProviderConfig(config) if err != nil { + log.Errorf(" P (Autogen): failed to parse provider config %+v", err) return v1alpha2.NewCOAError(nil, "provided config is not a valid cert generation provider config", v1alpha2.InvalidArgument) } w.Config = certConfig diff --git a/coa/pkg/apis/v1alpha2/providers/certs/localfile/localfile.go b/coa/pkg/apis/v1alpha2/providers/certs/localfile/localfile.go index f2d9c8959..ff9c2423a 100644 --- a/coa/pkg/apis/v1alpha2/providers/certs/localfile/localfile.go +++ b/coa/pkg/apis/v1alpha2/providers/certs/localfile/localfile.go @@ -14,8 +14,11 @@ import ( "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2" "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/contexts" "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/providers" + "github.com/eclipse-symphony/symphony/coa/pkg/logger" ) +var log = logger.NewLogger("coa.runtime") + type LocalCertFileProviderConfig struct { Name string `json:"name"` CertFile string `json:"cert"` @@ -34,6 +37,7 @@ func (s *LocalCertFileProvider) SetContext(ctx contexts.ManagerContext) { func (w *LocalCertFileProvider) Init(config providers.IProviderConfig) error { certConfig, err := toLocalCertFileProviderConfig(config) if err != nil { + log.Errorf(" P (Localfile): expect LocalCertFileProviderConfig %+v", err) return v1alpha2.NewCOAError(nil, "provided config is not a valid local cert file provider config", v1alpha2.InvalidArgument) } w.Config = certConfig @@ -44,6 +48,7 @@ func toLocalCertFileProviderConfig(config providers.IProviderConfig) (LocalCertF ret := LocalCertFileProviderConfig{} data, err := json.Marshal(config) if err != nil { + log.Errorf(" P (Localfile): failed to marshall config %+v", err) return ret, err } err = json.Unmarshal(data, &ret) @@ -53,18 +58,22 @@ func toLocalCertFileProviderConfig(config providers.IProviderConfig) (LocalCertF func (w *LocalCertFileProvider) GetCert(host string) ([]byte, []byte, error) { certFile, err := os.Open(w.Config.CertFile) if err != nil { + log.Errorf(" P (Localfile): failed to open certificate file %+v", err) return nil, nil, v1alpha2.NewCOAError(err, "failed to read certificate file", v1alpha2.InternalError) } certData, err := ioutil.ReadAll(certFile) if err != nil { + log.Errorf(" P (Localfile): failed to read certificate file %+v", err) return nil, nil, v1alpha2.NewCOAError(err, "failed to read certificate file", v1alpha2.InternalError) } keyFile, err := os.Open(w.Config.KeyFile) if err != nil { + log.Errorf(" P (Localfile): failed to open key file %+v", err) return nil, nil, v1alpha2.NewCOAError(err, "failed to read key file", v1alpha2.InternalError) } keyData, err := ioutil.ReadAll(keyFile) if err != nil { + log.Errorf(" P (Localfile): failed to read key file %+v", err) return nil, nil, v1alpha2.NewCOAError(err, "failed to read key file", v1alpha2.InternalError) } return certData, keyData, nil diff --git a/coa/pkg/apis/v1alpha2/providers/pubsub/memory/memory.go b/coa/pkg/apis/v1alpha2/providers/pubsub/memory/memory.go index 28460e6a0..86b61257a 100644 --- a/coa/pkg/apis/v1alpha2/providers/pubsub/memory/memory.go +++ b/coa/pkg/apis/v1alpha2/providers/pubsub/memory/memory.go @@ -12,8 +12,11 @@ import ( "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2" contexts "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/contexts" providers "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/providers" + "github.com/eclipse-symphony/symphony/coa/pkg/logger" ) +var log = logger.NewLogger("coa.runtime") + type InMemoryPubSubProvider struct { Config InMemoryPubSubConfig `json:"config"` Subscribers map[string][]v1alpha2.EventHandler `json:"subscribers"` @@ -43,6 +46,7 @@ func (s *InMemoryPubSubProvider) SetContext(ctx *contexts.ManagerContext) { func (i *InMemoryPubSubProvider) InitWithMap(properties map[string]string) error { config, err := InMemoryPubSubConfigFromMap(properties) if err != nil { + log.Errorf(" P (Memory PubSub): failed to parse provider config from map %+v", err) return err } return i.Init(config) @@ -51,6 +55,7 @@ func (i *InMemoryPubSubProvider) InitWithMap(properties map[string]string) error func (i *InMemoryPubSubProvider) Init(config providers.IProviderConfig) error { vConfig, err := toInMemoryPubSubConfig(config) if err != nil { + log.Errorf(" P (Memory PubSub): failed to parse provider config %+v", err) return v1alpha2.NewCOAError(nil, "provided config is not a valid in-memory pub-sub provider config", v1alpha2.BadConfig) } i.Config = vConfig diff --git a/coa/pkg/apis/v1alpha2/providers/pubsub/redis/redis.go b/coa/pkg/apis/v1alpha2/providers/pubsub/redis/redis.go index db653ba81..e41b3f90a 100644 --- a/coa/pkg/apis/v1alpha2/providers/pubsub/redis/redis.go +++ b/coa/pkg/apis/v1alpha2/providers/pubsub/redis/redis.go @@ -152,6 +152,7 @@ func (i *RedisPubSubProvider) InitWithMap(properties map[string]string) error { func (i *RedisPubSubProvider) Init(config providers.IProviderConfig) error { vConfig, err := toRedisPubSubProviderConfig(config) if err != nil { + mLog.Debugf(" P (Redis PubSub): failed to parse provider config %+v", err) return v1alpha2.NewCOAError(nil, "provided config is not a valid redis pub-sub provider config", v1alpha2.BadConfig) } i.Config = vConfig @@ -174,6 +175,7 @@ func (i *RedisPubSubProvider) Init(config providers.IProviderConfig) error { } client := redis.NewClient(options) if _, err := client.Ping().Result(); err != nil { + mLog.Debugf(" P (Redis PubSub): failed to connect to redis %+v", err) return v1alpha2.NewCOAError(err, fmt.Sprintf("redis stream: error connecting to redis at %s", i.Config.Host), v1alpha2.InternalError) } i.Client = client diff --git a/coa/pkg/apis/v1alpha2/providers/states/httpstate/httpstate.go b/coa/pkg/apis/v1alpha2/providers/states/httpstate/httpstate.go index e31e9dea2..451609490 100644 --- a/coa/pkg/apis/v1alpha2/providers/states/httpstate/httpstate.go +++ b/coa/pkg/apis/v1alpha2/providers/states/httpstate/httpstate.go @@ -19,11 +19,16 @@ import ( "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2" contexts "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/contexts" + "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/observability" + observ_utils "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/observability/utils" providers "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/providers" states "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/providers/states" "github.com/eclipse-symphony/symphony/coa/pkg/apis/v1alpha2/utils" + "github.com/eclipse-symphony/symphony/coa/pkg/logger" ) +var sLog = logger.NewLogger("coa.runtime") + type HttpStateProviderConfig struct { Name string `json:"name"` Url string `json:"url"` @@ -102,6 +107,7 @@ func (s *HttpStateProvider) SetContext(ctx *contexts.ManagerContext) { func (i *HttpStateProvider) InitWithMap(properties map[string]string) error { config, err := HttpStateProviderConfigFromMap(properties) if err != nil { + sLog.Errorf(" P (Http State): failed to parse provider config from map %+v", err) return err } return i.Init(config) @@ -111,24 +117,37 @@ func (s *HttpStateProvider) Init(config providers.IProviderConfig) error { // parameter checks stateConfig, err := toHttpStateProviderConfig(config) if err != nil { + sLog.Errorf(" P (Http State): failed to parse provider config %+v", err) return errors.New("expected HttpStateProviderConfig") } s.Config = stateConfig if s.Config.Url == "" { - return v1alpha2.NewCOAError(nil, "Http sate provider url is not set", v1alpha2.BadConfig) + return v1alpha2.NewCOAError(nil, "Http state provider url is not set", v1alpha2.BadConfig) } s.Data = make(map[string]interface{}, 0) return nil } func (s *HttpStateProvider) Upsert(ctx context.Context, entry states.UpsertRequest) (string, error) { + _, span := observability.StartSpan("Http State Provider", ctx, &map[string]string{ + "method": "Upsert", + }) + var err error = nil + defer observ_utils.CloseSpanWithError(span, &err) + sLog.Infof(" P (Http State): upsert states %s, traceId: %s", entry.Value.ID, span.SpanContext().TraceID().String()) + client := &http.Client{} rUrl := s.Config.Url - var err error + if entry.Value.ID == "" { + err = v1alpha2.NewCOAError(nil, "found invalid entry ID", v1alpha2.InternalError) + sLog.Errorf(" P (Http State): upsert failed %+v, traceId: %s", err, span.SpanContext().TraceID().String()) + return "", err + } if s.Config.PostNameInPath { rUrl, err = url.JoinPath(s.Config.Url, entry.Value.ID) } if err != nil { + sLog.Errorf(" P (Http State): failed to form %s request path: %+v, traceId: %s", entry.Value.ID, err, span.SpanContext().TraceID().String()) return "", err } obj := entry.Value.Body @@ -144,64 +163,100 @@ func (s *HttpStateProvider) Upsert(ctx context.Context, entry states.UpsertReque jData, _ := json.Marshal(obj) req, err := http.NewRequest("POST", rUrl, bytes.NewBuffer(jData)) if err != nil { + sLog.Errorf(" P (Http State): failed to create a Post request: %+v, traceId: %s", entry.Value.ID, err, span.SpanContext().TraceID().String()) return "", err } resp, err := client.Do(req) if err != nil { + sLog.Errorf(" P (Http State): failed to get response from upserting %s: %+v, traceId: %s", entry.Value.ID, err, span.SpanContext().TraceID().String()) return "", err } if resp.StatusCode >= 300 { + sLog.Errorf(" P (Http State): failed to get correct state code: %+v, status code %d, traceId: %s", entry.Value.ID, resp.StatusCode, err, span.SpanContext().TraceID().String()) return "", fmt.Errorf("failed to invoke HTTP state store: [%d]", resp.StatusCode) } return entry.Value.ID, nil } func (s *HttpStateProvider) List(ctx context.Context, request states.ListRequest) ([]states.StateEntry, string, error) { - return nil, "", v1alpha2.NewCOAError(nil, "Http sate store list is not implemented", v1alpha2.NotImplemented) + return nil, "", v1alpha2.NewCOAError(nil, "Http state store list is not implemented", v1alpha2.NotImplemented) } func (s *HttpStateProvider) Delete(ctx context.Context, request states.DeleteRequest) error { + _, span := observability.StartSpan("Http State Provider", ctx, &map[string]string{ + "method": "Delete", + }) + var err error = nil + defer observ_utils.CloseSpanWithError(span, &err) + sLog.Infof(" P (Http State): list states, traceId: %s", span.SpanContext().TraceID().String()) + client := &http.Client{} + if request.ID == "" { + err := v1alpha2.NewCOAError(nil, "found invalid request ID", v1alpha2.InternalError) + sLog.Errorf(" P (Http State): failed to list states: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) + return err + } rUrl, err := url.JoinPath(s.Config.Url, request.ID) if err != nil { + sLog.Errorf(" P (Http State): failed to form %s request path: %+v, traceId: %s", request.ID, err, span.SpanContext().TraceID().String()) return err } req, err := http.NewRequest("DELETE", rUrl, nil) if err != nil { + sLog.Errorf(" P (Http State): failed to create a Delete request: %+v, traceId: %s", request.ID, err, span.SpanContext().TraceID().String()) return err } resp, err := client.Do(req) if err != nil { + sLog.Errorf(" P (Http State): failed to get response from upserting %s: %+v, traceId: %s", request.ID, err, span.SpanContext().TraceID().String()) return err } if resp.StatusCode >= 300 { + sLog.Errorf(" P (Http State): failed to get correct state code: %+v, status code %d, traceId: %s", request.ID, resp.StatusCode, err, span.SpanContext().TraceID().String()) return v1alpha2.NewCOAError(nil, fmt.Sprintf("failed to delete from HTTP state store: [%d]", resp.StatusCode), v1alpha2.InternalError) - } return nil } func (s *HttpStateProvider) Get(ctx context.Context, request states.GetRequest) (states.StateEntry, error) { + _, span := observability.StartSpan("Http State Provider", ctx, &map[string]string{ + "method": "Delete", + }) + var err error = nil + defer observ_utils.CloseSpanWithError(span, &err) + sLog.Infof(" P (Http State): get states %s, traceId: %s", request.ID, span.SpanContext().TraceID().String()) + client := &http.Client{} + if request.ID == "" { + err := v1alpha2.NewCOAError(nil, "found invalid request ID", v1alpha2.InternalError) + sLog.Errorf(" P (Http State): failed to get states: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) + return states.StateEntry{}, err + } rUrl, err := url.JoinPath(s.Config.Url, request.ID) if err != nil { + sLog.Errorf(" P (Http State): failed to create a Get request: %+v, traceId: %s", request.ID, err, span.SpanContext().TraceID().String()) return states.StateEntry{}, err } req, err := http.NewRequest("GET", rUrl, nil) if err != nil { + sLog.Errorf(" P (Http State): request creation failed: %+v, traceId: %s", request.ID, err, span.SpanContext().TraceID().String()) return states.StateEntry{}, err } resp, err := client.Do(req) if err != nil { + sLog.Errorf(" P (Http State): failed to get response from getting %s: %+v, traceId: %s", request.ID, err, span.SpanContext().TraceID().String()) return states.StateEntry{}, err } if resp.StatusCode == 204 && s.Config.NotFoundAs204 { + sLog.Infof(" P (Http State): cannot find %s state: %+v, traceId: %s", request.ID, err, span.SpanContext().TraceID().String()) return states.StateEntry{}, v1alpha2.NewCOAError(nil, "not found", v1alpha2.NotFound) } if resp.StatusCode >= 300 { if resp.StatusCode == 404 { + sLog.Infof(" P (Http State): received 404 status code: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return states.StateEntry{}, v1alpha2.NewCOAError(nil, "not found", v1alpha2.NotFound) } else { + sLog.Errorf(" P (Http State): failed to get correct state code: %+v, status code %d, traceId: %s", request.ID, resp.StatusCode, err, span.SpanContext().TraceID().String()) return states.StateEntry{}, v1alpha2.NewCOAError(nil, fmt.Sprintf("failed to invoke HTTP state store: [%d]", resp.StatusCode), v1alpha2.InternalError) } @@ -209,11 +264,13 @@ func (s *HttpStateProvider) Get(ctx context.Context, request states.GetRequest) defer resp.Body.Close() bodyBytes, err := ioutil.ReadAll(resp.Body) if err != nil { + sLog.Errorf(" P (Http State): failed to read request body: %+v, traceId: %s", resp.StatusCode, err, span.SpanContext().TraceID().String()) return states.StateEntry{}, err } var obj interface{} err = json.Unmarshal(bodyBytes, &obj) if err != nil { + sLog.Errorf(" P (Http State): failed to unmarshall response body: %+v, traceId: %s", resp.StatusCode, err, span.SpanContext().TraceID().String()) return states.StateEntry{}, err } return states.StateEntry{ diff --git a/coa/pkg/apis/v1alpha2/providers/states/httpstate/httpstate_test.go b/coa/pkg/apis/v1alpha2/providers/states/httpstate/httpstate_test.go index d52dfbec7..5c06fdec6 100644 --- a/coa/pkg/apis/v1alpha2/providers/states/httpstate/httpstate_test.go +++ b/coa/pkg/apis/v1alpha2/providers/states/httpstate/httpstate_test.go @@ -9,6 +9,7 @@ package httpstate import ( "context" "encoding/json" + "io/ioutil" "net/http" "net/http/httptest" "os" @@ -237,12 +238,48 @@ func TestGet(t *testing.T) { func TestUpsertGetDelete(t *testing.T) { ts := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { if r.Method == "GET" { + relativePath := r.URL.Path + if relativePath == "" || relativePath == "/" { + http.Error(w, "invalid path", http.StatusBadRequest) + return + } response := map[string]interface{}{ "key": "abc", } jsonResponse, _ := json.Marshal(response) w.Header().Set("Content-Type", "application/json") w.Write(jsonResponse) + } else if r.Method == "POST" { + var data []map[string]interface{} + body, _ := ioutil.ReadAll(r.Body) + err := json.Unmarshal([]byte(body), &data) + if err != nil { + http.Error(w, err.Error(), http.StatusBadRequest) + return + } + if len(data) == 0 { + http.Error(w, "invalid request body", http.StatusBadRequest) + return + } + firstItemKey := data[0]["key"].(string) + if firstItemKey == "" { + http.Error(w, "invalid request body", http.StatusBadRequest) + return + } + response := map[string]interface{}{ + "key": data[0]["key"], + "value": data[0]["value"], + } + jsonResponse, _ := json.Marshal(response) + w.Header().Set("Content-Type", "application/json") + w.Write(jsonResponse) + } else if r.Method == "DELETE" { + relativePath := r.URL.Path + if relativePath == "" || relativePath == "/" { + http.Error(w, "invalid path", http.StatusBadRequest) + return + } + w.Write([]byte("OK")) } else { w.Write([]byte("OK")) } @@ -258,6 +295,7 @@ func TestUpsertGetDelete(t *testing.T) { PostAsArray: true, NotFoundAs204: true, }) + assert.Nil(t, err) _, err = provider.Upsert(context.Background(), states.UpsertRequest{ Value: states.StateEntry{ @@ -277,6 +315,24 @@ func TestUpsertGetDelete(t *testing.T) { ID: "123", }) assert.Nil(t, err) + + _, err = provider.Upsert(context.Background(), states.UpsertRequest{ + Value: states.StateEntry{ + ID: "", + Body: TestPayload{}, + }, + }) + assert.NotNil(t, err) + + _, err = provider.Get(context.Background(), states.GetRequest{ + ID: "", + }) + assert.NotNil(t, err) + + err = provider.Delete(context.Background(), states.DeleteRequest{ + ID: "", + }) + assert.NotNil(t, err) } func TestClone(t *testing.T) { diff --git a/coa/pkg/apis/v1alpha2/providers/states/memorystate/memorystate.go b/coa/pkg/apis/v1alpha2/providers/states/memorystate/memorystate.go index 6d46c8005..bfef33066 100644 --- a/coa/pkg/apis/v1alpha2/providers/states/memorystate/memorystate.go +++ b/coa/pkg/apis/v1alpha2/providers/states/memorystate/memorystate.go @@ -65,6 +65,7 @@ func (s *MemoryStateProvider) Init(config providers.IProviderConfig) error { // parameter checks stateConfig, err := toMemoryStateProviderConfig(config) if err != nil { + sLog.Errorf(" P (Memory State): failed to parse provider config %+v", err) return errors.New("expected MemoryStateProviderConfig") } s.Config = stateConfig @@ -79,6 +80,7 @@ func (s *MemoryStateProvider) Upsert(ctx context.Context, entry states.UpsertReq _, span := observability.StartSpan("Memory State Provider", ctx, &map[string]string{ "method": "Upsert", }) + sLog.Debugf(" P (Memory State): upsert states %s, traceId: %s", entry.Value.ID, span.SpanContext().TraceID().String()) var err error = nil defer observ_utils.CloseSpanWithError(span, &err) @@ -96,6 +98,7 @@ func (s *MemoryStateProvider) Upsert(ctx context.Context, entry states.UpsertReq if _, ok := entry.Value.Body.(map[string]interface{}); ok { mapRef := entry.Value.Body.(map[string]interface{}) if mapRef["status"] != nil && mapRef["spec"] == nil { + dataRef := s.Data[entry.Value.ID] if dataRef != nil { mapRef["spec"] = dataRef.(states.StateEntry).Body.(map[string]interface{})["spec"] @@ -118,7 +121,7 @@ func (s *MemoryStateProvider) List(ctx context.Context, request states.ListReque var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Debug(" P (Memory State): list states") + sLog.Debugf(" P (Memory State): list states, traceId: %s", span.SpanContext().TraceID().String()) var entities []states.StateEntry for _, v := range s.Data { @@ -130,6 +133,7 @@ func (s *MemoryStateProvider) List(ctx context.Context, request states.ListReque entities = append(entities, vE) } else { err = v1alpha2.NewCOAError(nil, "found invalid state entry", v1alpha2.InternalError) + sLog.Errorf(" P (Memory State): failed to list states: %+v, traceId: %s", err, span.SpanContext().TraceID().String()) return entities, "", err } } @@ -146,10 +150,11 @@ func (s *MemoryStateProvider) Delete(ctx context.Context, request states.DeleteR var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Debug(" P (Memory State): delete state") + sLog.Debug(" P (Memory State): delete state %s, traceId: %s", request.ID, span.SpanContext().TraceID().String()) if _, ok := s.Data[request.ID]; !ok { err = v1alpha2.NewCOAError(nil, fmt.Sprintf("entry '%s' is not found", request.ID), v1alpha2.NotFound) + sLog.Errorf(" P (Memory State): failed to delete %s: %+v, traceId: %s", request.ID, err, span.SpanContext().TraceID().String()) return err } delete(s.Data, request.ID) @@ -166,7 +171,7 @@ func (s *MemoryStateProvider) Get(ctx context.Context, request states.GetRequest var err error = nil defer observ_utils.CloseSpanWithError(span, &err) - sLog.Debug(" P (Memory State): get state") + sLog.Debug(" P (Memory State): get state %s, traceId: %s", request.ID, span.SpanContext().TraceID().String()) if v, ok := s.Data[request.ID]; ok { vE, ok := v.(states.StateEntry) @@ -175,10 +180,12 @@ func (s *MemoryStateProvider) Get(ctx context.Context, request states.GetRequest return vE, nil } else { err = v1alpha2.NewCOAError(nil, fmt.Sprintf("entry '%s' is not a valid state entry", request.ID), v1alpha2.InternalError) + sLog.Errorf(" P (Memory State): failed to get %s state: %+v, traceId: %s", request.ID, err, span.SpanContext().TraceID().String()) return states.StateEntry{}, err } } err = v1alpha2.NewCOAError(nil, fmt.Sprintf("entry '%s' is not found", request.ID), v1alpha2.NotFound) + sLog.Errorf(" P (Memory State): failed to get %s state: %+v, traceId: %s", request.ID, err, span.SpanContext().TraceID().String()) return states.StateEntry{}, err } diff --git a/k8s/controllers/fabric/target_controller.go b/k8s/controllers/fabric/target_controller.go index 2126a0507..f512ce18e 100644 --- a/k8s/controllers/fabric/target_controller.go +++ b/k8s/controllers/fabric/target_controller.go @@ -81,6 +81,7 @@ func (r *TargetReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctr if err != nil && !v1alpha2.IsNotFound(err) { uErr := r.updateTargetStatusToReconciling(target, err) if uErr != nil { + log.Error(uErr, "failed to update target status to reconciling") return ctrl.Result{}, uErr } return ctrl.Result{}, err @@ -94,6 +95,7 @@ func (r *TargetReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctr if generationMatch && time.Since(summary.Time) <= time.Duration(60)*time.Second { //TODO: this is 60 second interval. Make if configurable? err = r.updateTargetStatus(target, summary.Summary) if err != nil { + log.Error(err, "failed to update target status") return ctrl.Result{}, err } return ctrl.Result{RequeueAfter: 60 * time.Second}, nil @@ -103,6 +105,7 @@ func (r *TargetReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctr if err != nil { uErr := r.updateTargetStatusToReconciling(target, err) if uErr != nil { + log.Error(uErr, "failed to update target status to reconciling") return ctrl.Result{}, uErr } return ctrl.Result{}, err @@ -117,6 +120,7 @@ func (r *TargetReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctr if !generationMatch { err = r.updateTargetStatusToReconciling(target, nil) if err != nil { + log.Error(err, "failed to update target status to reconciling") return ctrl.Result{}, err } } @@ -131,6 +135,7 @@ func (r *TargetReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctr if err != nil { uErr := r.updateTargetStatusToReconciling(target, err) if uErr != nil { + log.Error(uErr, "failed to update target status to reconciling") return ctrl.Result{}, uErr } return ctrl.Result{}, err @@ -149,6 +154,7 @@ func (r *TargetReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctr break loop } if err != nil && !v1alpha2.IsNotFound(err) { + log.Error(err, "failed to get target summary") break loop } } @@ -158,6 +164,7 @@ func (r *TargetReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctr // provider to pick up. controllerutil.RemoveFinalizer(target, myFinalizerName) if err := r.Update(ctx, target); err != nil { + log.Error(err, "failed to remove finalizer") return ctrl.Result{}, err } }