Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

GMC: enhance log #371

Merged
merged 12 commits into from
Sep 11, 2024
111 changes: 60 additions & 51 deletions microservices-connector/internal/controller/gmconnector_controller.go
Original file line number Diff line number Diff line change
Expand Up @@ -98,6 +98,10 @@ var yamlDict = map[string]string{
DataPrep: yaml_dir + "data-prep.yaml",
}

var (
_log = log.Log.WithName("GMC")
)

// GMConnectorReconciler reconciles a GMConnector object
type GMConnectorReconciler struct {
client.Client
Expand Down Expand Up @@ -128,7 +132,7 @@ func (r *GMConnectorReconciler) reconcileResource(ctx context.Context, graphNs s
return nil, errors.New("invalid svc config")
}

fmt.Printf("get resource config: %v\n", *stepCfg)
_log.V(2).Info("processing step", "config", *stepCfg)

var retObjs []*unstructured.Unstructured
// by default, the svc's namespace is the same as the graph
Expand All @@ -142,12 +146,11 @@ func (r *GMConnectorReconciler) reconcileResource(ctx context.Context, graphNs s

yamlFile, err := getTemplateBytes(stepCfg.StepName)
if err != nil {
return nil, fmt.Errorf("failed to read YAML file: %v", err)
_log.Error(err, "Failed to get template bytes for", "step", stepCfg.StepName)
return nil, err
}

resources := strings.Split(string(yamlFile), "---")
fmt.Printf("The raw yaml file has been split into %v yaml files\n", len(resources))

for _, res := range resources {
if res == "" || !strings.Contains(res, "kind:") {
continue
Expand All @@ -157,7 +160,8 @@ func (r *GMConnectorReconciler) reconcileResource(ctx context.Context, graphNs s
obj := &unstructured.Unstructured{}
_, _, err := decUnstructured.Decode([]byte(res), nil, obj)
if err != nil {
return nil, fmt.Errorf("failed to decode YAML: %v", err)
_log.Error(err, "Failed to decode YAML")
return nil, err
}

// Set the namespace according to user defined value
Expand All @@ -170,19 +174,22 @@ func (r *GMConnectorReconciler) reconcileResource(ctx context.Context, graphNs s
service_obj := &corev1.Service{}
err = scheme.Scheme.Convert(obj, service_obj, nil)
if err != nil {
return nil, fmt.Errorf("failed to convert unstructured to service %s: %v", svc, err)
_log.Error(err, "Failed to convert unstructured to service", "name", svc)
return nil, err
}
service_obj.SetName(svc)
service_obj.Spec.Selector["app"] = svc
err = scheme.Scheme.Convert(service_obj, obj, nil)
if err != nil {
return nil, fmt.Errorf("failed to convert service %s to object: %v", svc, err)
_log.Error(err, "Failed to convert service to object", "name", svc)
return nil, err
}
} else if obj.GetKind() == Deployment {
deployment_obj := &appsv1.Deployment{}
err = scheme.Scheme.Convert(obj, deployment_obj, nil)
if err != nil {
return nil, fmt.Errorf("failed to convert unstructured to deployment %s: %v", obj.GetName(), err)
_log.Error(err, "Failed to convert unstructured to deployment", "name", obj.GetName())
return nil, err
}
if svc != "" {
deployment_obj.SetName(svc + dplymtSubfix)
Expand All @@ -200,9 +207,9 @@ func (r *GMConnectorReconciler) reconcileResource(ctx context.Context, graphNs s
if isDownStreamEndpointKey(name) {
ds := findDownStreamService(value, stepCfg, nodeCfg)
value, err = getDownstreamSvcEndpoint(graphNs, value, ds)
// value = getDsEndpoint(platform, name, graphNs, ds)
if err != nil {
return nil, fmt.Errorf("failed to find downstream service endpoint %s-%s: %v", name, value, err)
_log.Error(err, "Failed to find downstream service endpoint", "name", name, "value", value)
return nil, err
}
}
itemEnvVar := corev1.EnvVar{
Expand All @@ -222,15 +229,17 @@ func (r *GMConnectorReconciler) reconcileResource(ctx context.Context, graphNs s

err = scheme.Scheme.Convert(deployment_obj, obj, nil)
if err != nil {
return nil, fmt.Errorf("failed to convert deployment %s to obj: %v", deployment_obj.GetName(), err)
_log.Error(err, "Failed to convert deployment to obj", "name", deployment_obj.GetName())
return nil, err
}
}

err = r.applyResourceToK8s(graph, ctx, obj)
if err != nil {
return nil, fmt.Errorf("failed to reconcile resource: %v", err)
_log.Error(err, "Failed to reconcile resource", "name", obj.GetName())
return nil, err
} else {
fmt.Printf("Success to reconcile %s: %s\n", obj.GetKind(), obj.GetName())
_log.Info("Success to reconcile resource", "kind", obj.GetKind(), "name", obj.GetName())
retObjs = append(retObjs, obj)
}
}
Expand All @@ -251,7 +260,7 @@ func findDownStreamService(dsName string, stepCfg *mcv1alpha3.Step, nodeCfg *mcv
if stepCfg == nil || nodeCfg == nil {
return nil
}
fmt.Printf("find downstream service for %s with name %s \n", stepCfg.StepName, dsName)
_log.Info("Find downstream service for step", "name", stepCfg.StepName, "downstream", dsName)

for _, otherStep := range nodeCfg.Steps {
if otherStep.InternalService.ServiceName == dsName && otherStep.InternalService.IsDownstreamService {
Expand Down Expand Up @@ -329,8 +338,8 @@ func getServiceURL(service *corev1.Service) string {
// For more details, check Reconcile and its Result here:
// - https://pkg.go.dev/sigs.k8s.io/[email protected]/pkg/reconcile
func (r *GMConnectorReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) {
_ = log.FromContext(ctx)
fmt.Println("-----------------Reconciling GMConnector", req, "-------------------------")
// _ = log.FromContext(ctx)
_log.Info("----RECONCILE REQUEST----", "req", req)

graph := &mcv1alpha3.GMConnector{}
if err := r.Get(ctx, req.NamespacedName, graph); err != nil {
Expand All @@ -341,7 +350,7 @@ func (r *GMConnectorReconciler) Reconcile(ctx context.Context, req ctrl.Request)
if err == nil {
return r.handleStatusUpdate(ctx, deployment)
} else {
fmt.Printf("resource %s not found or deleted, %v, ignore\n", req.Name, err)
_log.Info("Resource not found or deleted, ignore", "name", req.Name, "err", err)
return ctrl.Result{}, nil
}
} else {
Expand All @@ -358,9 +367,6 @@ func (r *GMConnectorReconciler) Reconcile(ctx context.Context, req ctrl.Request)
}
}

// r.Log.Info("Reconciling connector graph", "apiVersion", graph.APIVersion, "graph", graph.Name)
fmt.Println("Reconciling kind ", graph.Kind, "apiVersion ", graph.APIVersion, " graph ", graph.Name)

var totalService uint
var externalService uint
var updateExistGraph bool = false
Expand All @@ -378,13 +384,13 @@ func (r *GMConnectorReconciler) Reconcile(ctx context.Context, req ctrl.Request)
for nodeName, node := range graph.Spec.Nodes {
for i, step := range node.Steps {
if step.NodeName != "" {
fmt.Println("\nthis is a nested step: ", step.StepName)
_log.Info("This is a nested step", "step", step.StepName)
continue
}
fmt.Println("\nreconcile resource for node:", step.StepName)
_log.Info("Reconcile step", "graph", graph.Name, "name", step.StepName)
totalService += 1
if step.Executor.ExternalService == "" {
fmt.Println("trying to reconcile internal service [", step.Executor.InternalService.ServiceName, "] in namespace ", step.Executor.InternalService.NameSpace)
_log.Info("Trying to reconcile internal service", " service", step.Executor.InternalService.ServiceName)

objs, err := r.reconcileResource(ctx, graph.Namespace, &step, &node, graph)
if err != nil {
Expand All @@ -399,12 +405,11 @@ func (r *GMConnectorReconciler) Reconcile(ctx context.Context, req ctrl.Request)
}
}
} else {
fmt.Println("external service is found", "name", step.ExternalService)
_log.Info("External service is found", "name", step.ExternalService)
graph.Spec.Nodes[nodeName].Steps[i].ServiceURL = step.ExternalService
externalService += 1
}
}
fmt.Println()
}

//to start a router service
Expand Down Expand Up @@ -443,7 +448,7 @@ func (r *GMConnectorReconciler) handleStatusUpdate(ctx context.Context, deployme
if err == nil {
ue := r.collectResourceStatus(graph, ctx)
if ue != nil {
fmt.Printf("failed to get graph before update status %s %v\n", graph.Name, err)
_log.Error(err, "Failed to get graph before update status", "name", graph.Name)
return reconcile.Result{}, err
}
}
Expand All @@ -467,9 +472,9 @@ func (r *GMConnectorReconciler) deleteRecordedResource(key string, ctx context.C
// ignore the error if delete failed i.e resource not found
// since I don't want to block the process for not clearing the finalizer
if err != nil {
fmt.Printf("Failed to delete resource %s:%s:%s: %v\n", ns, kind, name, err)
_log.Info("Failed to delete resource", "namespace", ns, "kind", kind, "name", name, "error", err)
} else {
fmt.Printf("Success to delete %s:%s:%s\n", ns, kind, name)
_log.Info("Success to delete resource", "namespace", ns, "kind", kind, "name", name)
}
}

Expand All @@ -487,7 +492,7 @@ func (r *GMConnectorReconciler) collectResourceStatus(graph *mcv1alpha3.GMConnec
deployment := &appsv1.Deployment{}
err := r.Get(ctx, client.ObjectKey{Namespace: ns, Name: name}, deployment)
if err != nil {
fmt.Printf("Collecting status: failed to get deployment %s: %v\n", name, err)
_log.Info("Collecting status: failed to get deployment", "name", name, "error", err)
continue
}
var deploymentStatus strings.Builder
Expand Down Expand Up @@ -521,7 +526,7 @@ func (r *GMConnectorReconciler) collectResourceStatus(graph *mcv1alpha3.GMConnec
var latestGraph mcv1alpha3.GMConnector
err = r.Client.Get(ctx, types.NamespacedName{Namespace: graph.Namespace, Name: graph.Name}, &latestGraph)
if err != nil && apierr.IsNotFound(err) {
fmt.Printf("failed to get graph %s before update status : %s\n", graph.Name, err)
_log.Info("Failed to get graph before update status", "name", graph.Name, "error", err)
} else {
graph.SetResourceVersion(latestGraph.GetResourceVersion())
}
Expand Down Expand Up @@ -549,12 +554,12 @@ func recordResource(graph *mcv1alpha3.GMConnector, nodeName string, stepIdx int,
//set this for router
graph.Spec.Nodes[nodeName].Steps[stepIdx].ServiceURL = url
graph.Status.Annotations[fmt.Sprintf("%s:%s:%s:%s", obj.GetKind(), obj.GetAPIVersion(), obj.GetName(), obj.GetNamespace())] = url
fmt.Printf("the service URL is: %s\n", url)
_log.Info("Service URL is: ", "URL", url)
} else {
url := getServiceURL(service)
graph.Status.Annotations[fmt.Sprintf("%s:%s:%s:%s", obj.GetKind(), obj.GetAPIVersion(), obj.GetName(), obj.GetNamespace())] = url
graph.Status.AccessURL = url
fmt.Printf("the router URL is: %s\n", url)
_log.Info("Router URL is: ", "URL", url)
}
}
return nil
Expand All @@ -567,7 +572,7 @@ func getTemplateBytes(resourceType string) ([]byte, error) {
}
yamlBytes, err := os.ReadFile(tmpltFile)
if err != nil {
return nil, fmt.Errorf("failed to read YAML file: %v", err)
return nil, err
}
return yamlBytes, nil
}
Expand Down Expand Up @@ -614,7 +619,8 @@ func (r *GMConnectorReconciler) reconcileRouterService(ctx context.Context, grap
var resources []string
appliedCfg, err := applyRouterConfigToTemplates(Router, &configForRouter, templateBytes)
if err != nil {
return fmt.Errorf("failed to apply user config: %v", err)
_log.Error(err, "Failed to apply user config")
return err
}

resources = strings.Split(appliedCfg, "---")
Expand All @@ -626,19 +632,22 @@ func (r *GMConnectorReconciler) reconcileRouterService(ctx context.Context, grap
obj := &unstructured.Unstructured{}
_, _, err := decUnstructured.Decode([]byte(res), nil, obj)
if err != nil {
return fmt.Errorf("failed to decode YAML: %v", err)
_log.Error(err, "Failed to decode YAML")
return err
}

err = r.applyResourceToK8s(graph, ctx, obj)
if err != nil {
return fmt.Errorf("failed to reconcile resource: %v", err)
_log.Error(err, "Failed to reconcile resource", "name", obj.GetName())
return err
} else {
fmt.Printf("Success to reconcile %s: %s\n", obj.GetKind(), obj.GetName())
_log.Info("Success to reconcile resource", "kind", obj.GetKind(), "name", obj.GetName())
}
// save the resource name into annotation for status update and resource management
err = recordResource(graph, "", 0, obj)
if err != nil {
return fmt.Errorf("resource created with failure %s: %v", obj.GetName(), err)
_log.Error(err, "Resource created with failure", "name", obj.GetName())
return err
}
}

Expand All @@ -656,7 +665,7 @@ func applyRouterConfigToTemplates(step string, svcCfg *map[string]string, yamlFi
HttpProxy: (*svcCfg)["http_proxy"],
HttpsProxy: (*svcCfg)["https_proxy"],
GRAPH_JSON: (*svcCfg)["nodes"]}
fmt.Printf("user config %v\n", userDefinedCfg)
_log.Info("Apply the config to router", "content", userDefinedCfg)

tmpl, err := template.New("yamlTemplate").Parse(string(yamlFile))
if err != nil {
Expand Down Expand Up @@ -706,15 +715,15 @@ func (r *GMConnectorReconciler) applyResourceToK8s(graph *mcv1alpha3.GMConnector
}
} else {
// If there was another error, continue
fmt.Printf("get object err: %v", err)
_log.Info("Get object err", "message", err)
continue
}
} else {
// If the object does exist, update it
obj.SetResourceVersion(latest.GetResourceVersion()) // Ensure we're updating the latest version
err = r.Client.Update(ctx, obj, &client.UpdateOptions{})
if err != nil {
fmt.Printf("update object err: %v\n", err)
_log.Info("Update object err", "message", err)
continue
}
}
Expand Down Expand Up @@ -773,24 +782,24 @@ func getServiceDetailsFromManifests(filePath string) (string, int, error) {

func isMetadataChanged(oldObject, newObject *metav1.ObjectMeta) bool {
if oldObject == nil || newObject == nil {
fmt.Printf("Metadata changes detected, old/new object is nil\n")
_log.Info("Metadata changes detected, old/new object is nil")
return oldObject != newObject
}
// only care limited changes
if oldObject.Name != newObject.Name {
fmt.Printf("Metadata changes detected, Name changed from %s to %s\n", oldObject.Name, newObject.Name)
_log.Info("Metadata.Name changes detected", "old", oldObject.Name, "new", newObject.Name)
return true
}
if oldObject.Namespace != newObject.Namespace {
fmt.Printf("Metadata changes detected, Namespace changed from %s to %s\n", oldObject.Namespace, newObject.Namespace)
_log.Info("Metadata.Namespace changes detected", "old", oldObject.Namespace, "new", newObject.Namespace)
return true
}
if !reflect.DeepEqual(oldObject.Labels, newObject.Labels) {
fmt.Printf("Metadata changes detected, Labels changed from %v to %v\n", oldObject.Labels, newObject.Labels)
_log.Info("Metadata.Labels changes detected", "old", oldObject.Labels, "new", newObject.Labels)
return true
}
if !reflect.DeepEqual(oldObject.DeletionTimestamp, newObject.DeletionTimestamp) {
fmt.Printf("Metadata changes detected, DeletionTimestamp changed from %v to %v\n", oldObject.DeletionTimestamp, newObject.DeletionTimestamp)
_log.Info("Metadata.DeletionTimestamp changes detected", "old", oldObject.DeletionTimestamp, "new", newObject.DeletionTimestamp)
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Shall this be on Debug level instead of Info level?

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

from my view, this information is kind of useful for me, to know what condition trigger the reconcile, we don't want unexpected reconcile, if we hide this information to Debug, it would be less easier to find out such problem, espically for un-experienced developers.
Besides, there is no log.Debug, instead, it's log.V(2).Info

Copy link
Collaborator

@irisdingbj irisdingbj Sep 3, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We should add an option when controller start, to let user select the log level they want to set, eg: --logLevel debug
in such case, they can have much info in logs.
It does not make sense to have most info output to Info level by default.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We should add an option when controller start, to let user select the log level they want to set, eg: --logLevel debug in such case, they can have much info in logs. It does not make sense to have most info output to Info level by default.

it's implemented

return true
}
// Add more fields as needed
Expand All @@ -813,7 +822,7 @@ func (r *GMConnectorReconciler) SetupWithManager(mgr ctrl.Manager) error {
specChanged := !reflect.DeepEqual(oldObject.Spec, newObject.Spec)
metadataChanged := isMetadataChanged(&(oldObject.ObjectMeta), &(newObject.ObjectMeta))

fmt.Printf("\n| spec changed %t | meta changed: %t |\n", specChanged, metadataChanged)
_log.Info("Check trigger condition?", "spec changed", specChanged, "meta changed", metadataChanged)

// Compare the old and new spec, ignore metadata, status changes
// metadata change: name, namespace, such change should create a new GMC
Expand All @@ -831,7 +840,7 @@ func (r *GMConnectorReconciler) SetupWithManager(mgr ctrl.Manager) error {
newDeployment, ok2 := e.ObjectNew.(*appsv1.Deployment)
if !ok1 || !ok2 {
// Not the correct type, allow the event through
fmt.Printf("| status missing |\n")
_log.Info("Status missing")
return true
}

Expand Down Expand Up @@ -868,9 +877,9 @@ func (r *GMConnectorReconciler) SetupWithManager(mgr ctrl.Manager) error {
if (oldStatus == corev1.ConditionTrue && oldStatus != newStatus) ||
(newStatus == corev1.ConditionTrue && oldStatus != newStatus) {
{
fmt.Printf("| %s:%s: status changed from : %v to %v|\n",
newDeployment.Namespace, newDeployment.Name,
oldStatus, newStatus)
_log.Info("|Status changed|", "namespace",
newDeployment.Namespace, "name", newDeployment.Name,
"old", oldStatus, "new", newStatus)
return true
}
}
Expand Down
Loading