feat: improved error logging

f2soperator/operation/apiserver/authorization.go

@@ -60,7 +60,7 @@ func getUsers() ([]queue.F2SAuthUser, error) {
 				return []byte(jwtSecret), nil
 			})
 			if err != nil {
-				logging.Error(fmt.Sprintf("error decoding token '%s': %s", f2shub.F2SConfiguration.Config.F2S.Auth.Token.Tokens[i].Token, err.Error()))
+				logging.Error(fmt.Errorf("error decoding token '%s': %s", f2shub.F2SConfiguration.Config.F2S.Auth.Token.Tokens[i].Token, err.Error()))
 				continue
 			}
 

f2soperator/operation/apiserver/functions.go

@@ -73,7 +73,7 @@ func createFunction(w http.ResponseWriter, r *http.Request) {
 
 	// Unmarshal the JSON data into the function struct
 	if err := json.Unmarshal(body, &function); err != nil {
-		logging.Error(fmt.Sprintf("%s", err))
+		logging.Error(err)
 		http.Error(w, "Failed to parse JSON data", http.StatusBadRequest)
 		return
 	}

f2soperator/operation/apiserver/invoke.go

@@ -73,7 +73,7 @@ func invokeFunction(w http.ResponseWriter, r *http.Request) {
 	// get user info
 	currentUser, getUserErr := getCurrentUser(r)
 	if getUserErr != nil {
-		logging.Error(fmt.Sprintf("[%s] failed to get user info for this request", request.UID))
+		logging.Error(fmt.Errorf("[%s] failed to get user info for this request", request.UID))
 	}
 	request.F2SUser = currentUser
 
@@ -82,7 +82,7 @@ func invokeFunction(w http.ResponseWriter, r *http.Request) {
 		logging.Debug(fmt.Sprintf("[%s] reading request body", request.UID))
 		body, err := io.ReadAll(r.Body)
 		if err != nil {
-			logging.Error(fmt.Sprintf("[%s] Failed to read request body", request.UID))
+			logging.Error(fmt.Errorf("[%s] Failed to read request body", request.UID))
 			http.Error(w, "Failed to read request body", http.StatusInternalServerError)
 			return
 		}

f2soperator/operation/apiserver/prometheus.go

@@ -18,7 +18,7 @@ func getPrometheusMetric(w http.ResponseWriter, r *http.Request) {
 
 	result, err := prometheus.ReadPrometheusMetric(f2shub.F2SConfiguration, query)
 	if err != nil {
-		logging.Error(fmt.Sprintf("could not read prometheus metric: %s", err))
+		logging.Error(fmt.Errorf("could not read prometheus metric: %s", err))
 		json.NewEncoder(w).Encode(Status{Status: fmt.Sprintf("could not read prometheus metric %s", err)})
 		return
 	}

f2soperator/operation/dispatcher/handlerequest.go

@@ -80,8 +80,7 @@ func handleRequest(req *queue.F2SRequest, result *chan queue.F2SRequestResult) {
 	logging.Debug(fmt.Sprintf("[%s] search function target for endpoint: %s", req.UID, req.Path))
 	functionTarget, err := f2shub.F2SDispatcherHub.GetDispatcherFunctionByEndpoint(req.Path)
 	if err != nil {
-		logging.Error(fmt.Sprintf("[%s] cannot serve request. function target not found for endpoint %s", req.UID, req.Path))
-		logging.Error(fmt.Sprintf("%s", err))
+		logging.Error(fmt.Errorf("[%s] cannot serve request. function target not found for endpoint %s: %s", req.UID, req.Path, err.Error()))
 	}
 	logging.Debug(fmt.Sprintf("[%s] function target is: %s", req.UID, functionTarget.Function.Name))
 
@@ -110,7 +109,7 @@ func handleRequest(req *queue.F2SRequest, result *chan queue.F2SRequestResult) {
 	if len(functionTarget.ServingPods) == 0 {
 		err := waitForTargetPod(functionTarget)
 		if err != nil {
-			logging.Error(fmt.Sprintf("[%s] aborting function '%s'. scale from 0 failed: %s", req.UID, functionTarget.Function.Name, err.Error()))
+			logging.Error(fmt.Errorf("[%s] aborting function '%s'. scale from 0 failed: %s", req.UID, functionTarget.Function.Name, err.Error()))
 			// send result to channel
 			requestResult.Details = fmt.Sprintf("[%s] aborting function '%s'. scale from 0 failed: %s", req.UID, functionTarget.Function.Name, err.Error())
 			requestResult.Success = false
@@ -122,7 +121,7 @@ func handleRequest(req *queue.F2SRequest, result *chan queue.F2SRequestResult) {
 	// get the pod that will actually serve the request
 	pod, err := functionTarget.ServeRequest(req)
 	if err != nil {
-		logging.Error(fmt.Sprintf("[%s] cannot serve request because cannot determine which pod should serve the request: %s", req.UID, err.Error()))
+		logging.Error(fmt.Errorf("[%s] cannot serve request because cannot determine which pod should serve the request: %s", req.UID, err.Error()))
 		requestResult.Details = fmt.Sprintf("[%s] aborting function '%s' invocation because target cannot serve request: %s", req.UID, functionTarget.Function.Name, err.Error())
 		requestResult.Success = false
 		*result <- requestResult
@@ -166,7 +165,7 @@ func handleRequest(req *queue.F2SRequest, result *chan queue.F2SRequestResult) {
 	}
 
 	if requestErr != nil {
-		logging.Error(fmt.Sprintf("%s", err))
+		logging.Error(requestErr)
 		// send result to channel
 		requestResult.Details = fmt.Sprintf("[%s] error on function http invocation: %s", req.UID, requestErr.Error())
 		requestResult.Success = false

f2soperator/operation/dispatcher/httpget.go

@@ -21,10 +21,10 @@ func httpGet(url string, result *queue.F2SRequestResult) error {
 	response, err := client.Get(url)
 	if err != nil {
 		if strings.Contains(err.Error(), "context deadline exceeded") {
-			logging.Error(fmt.Sprintf("[%s] http_timeout: %s", result.Request.UID, err))
+			logging.Error(fmt.Errorf("[%s] http_timeout: %s", result.Request.UID, err.Error()))
 			return fmt.Errorf("http_timeout: %s", err)
 		} else {
-			logging.Error(fmt.Sprintf("[%s] error during httpGet function Call: %s", result.Request.UID, err))
+			logging.Error(fmt.Errorf("[%s] error during httpGet function Call: %s", result.Request.UID, err.Error()))
 			return err
 		}
 
@@ -64,10 +64,10 @@ func httpPost(url, data string, result *queue.F2SRequestResult) error {
 	response, err := client.Post(url, contentType, body)
 	if err != nil {
 		if strings.Contains(err.Error(), "context deadline exceeded") {
-			logging.Error(fmt.Sprintf("http_timeout: %s", err))
+			logging.Error(fmt.Errorf("http_timeout: %s", err.Error()))
 			return fmt.Errorf("http_timeout: %s", err)
 		} else {
-			logging.Error(fmt.Sprintf("[%s] error during httpPost function Call: %s", result.Request.UID, err))
+			logging.Error(fmt.Errorf("[%s] error during httpPost function Call: %s", result.Request.UID, err.Error()))
 			return err
 		}
 	}
@@ -93,7 +93,7 @@ func httpPut(url, data string, result *queue.F2SRequestResult) error {
 	// Create a PUT request using http.NewRequest
 	req, err := http.NewRequest("PUT", url, body)
 	if err != nil {
-		logging.Error(fmt.Sprintf("[%s] error creating PUT request: %s", result.Request.UID, err))
+		logging.Error(fmt.Errorf("[%s] error creating PUT request: %s", result.Request.UID, err.Error()))
 		return err
 	}
 
@@ -109,10 +109,10 @@ func httpPut(url, data string, result *queue.F2SRequestResult) error {
 	response, err := client.Do(req)
 	if err != nil {
 		if strings.Contains(err.Error(), "context deadline exceeded") {
-			logging.Error(fmt.Sprintf("[%s] http_timeout: %s", result.Request.UID, err))
-			return fmt.Errorf("http_timeout: %s", err)
+			logging.Error(fmt.Errorf("[%s] http_timeout: %s", result.Request.UID, err.Error()))
+			return fmt.Errorf("http_timeout: %s", err.Error())
 		} else {
-			logging.Error(fmt.Sprintf("[%s] error during httpPut function Call: %s", result.Request.UID, err))
+			logging.Error(fmt.Errorf("[%s] error during httpPut function Call: %s", result.Request.UID, err.Error()))
 			return err
 		}
 	}
@@ -135,18 +135,18 @@ func httpDelete(url string, result *queue.F2SRequestResult) error {
 	// Create a DELETE request using http.NewRequest
 	req, err := http.NewRequest("DELETE", url, nil)
 	if err != nil {
-		logging.Error(fmt.Sprintf("[%s] error creating DELETE request: %s", result.Request.UID, err))
+		logging.Error(fmt.Errorf("[%s] error creating DELETE request: %s", result.Request.UID, err.Error()))
 		return err
 	}
 
 	// Send the request using the client
 	response, err := client.Do(req)
 	if err != nil {
 		if strings.Contains(err.Error(), "context deadline exceeded") {
-			logging.Error(fmt.Sprintf("[%s] http_timeout: %s", result.Request.UID, err))
+			logging.Error(fmt.Errorf("[%s] http_timeout: %s", result.Request.UID, err.Error()))
 			return fmt.Errorf("http_timeout: %s", err)
 		} else {
-			logging.Error(fmt.Sprintf("[%s] error during httpDelete function Call: %s", result.Request.UID, err))
+			logging.Error(fmt.Errorf("[%s] error during httpDelete function Call: %s", result.Request.UID, err.Error()))
 			return err
 		}
 	}
@@ -165,7 +165,7 @@ func fetchResponse(response *http.Response, result *queue.F2SRequestResult) (err
 	// Read response body
 	responseBody, err := io.ReadAll(response.Body)
 	if err != nil {
-		logging.Error(fmt.Sprintf("[%s] [fetchResponse] error when reading httpPost function call result body: %s", result.Request.UID, err))
+		logging.Error(fmt.Errorf("[%s] [fetchResponse] error when reading httpPost function call result body: %s", result.Request.UID, err.Error()))
 		return err
 	}
 

f2soperator/operation/dispatcher/main.go

@@ -44,7 +44,7 @@ func GetCurrentDispatcherData() string {
 
 		// get function target
 		target, err := f2shub.F2SDispatcherHub.GetDispatcherFunctionByName(function.Name)
-		logging.Error(fmt.Sprintf("%s", err))
+		logging.Error(fmt.Errorf("could not get current dispatcher data: %s", err.Error()))
 
 		output += fmt.Sprintf("Endpoints: %d", len(target.ServingPods))
 		for _, endpoint := range target.ServingPods {

f2soperator/operation/kafka/invoker.go

@@ -15,7 +15,7 @@ func invokeFunction(functionUid string, requestBody string) (result string, err
 	// get this function from config
 	f2sfunction, errGetFunction := f2shub.F2SConfiguration.GetFunctionByUID(functionUid)
 	if errGetFunction != nil {
-		logging.Error(fmt.Sprintf("error getting function %s from running config. abort function invocation", functionUid))
+		logging.Error(fmt.Errorf("error getting function %s from running config. abort function invocation", functionUid))
 		return
 	}
 

f2soperator/operation/metrics/eventhandler.go

@@ -36,7 +36,7 @@ func handleEvent(event eventmanager.Event) {
 		result := event.Data.(queue.F2SRequestResult)
 		functionTarget, err := f2shub.F2SDispatcherHub.GetDispatcherFunctionByEndpoint(result.Request.Path)
 		if err != nil {
-			logging.Error(fmt.Sprintf("[%s] cannot calculate metrics for request because: %s", result.Request.UID, err.Error()))
+			logging.Error(fmt.Errorf("[%s] cannot calculate metrics for request because: %s", result.Request.UID, err.Error()))
 		}
 
 		if result.Success {

f2soperator/operation/operator/balancer.go

@@ -103,7 +103,7 @@ func getLastScalingTimestamp(deploymentName string) (time.Time, bool) {
 	// get annotations of k8s deployment
 	annotations, err := kubernetesservice.GetDeploymentAnnotations(deploymentName)
 	if err != nil {
-		logging.Error(fmt.Sprintf("could not get annotations of kubernetes deployment: %s", deploymentName))
+		logging.Error(fmt.Errorf("could not get annotations of kubernetes deployment '%s': %s", deploymentName, err.Error()))
 		return time.Time{}, false
 	}
 
@@ -114,7 +114,7 @@ func getLastScalingTimestamp(deploymentName string) (time.Time, bool) {
 		// convert to time.time
 		tm, err := convertMillisToTime(timestamp)
 		if err != nil {
-			logging.Error(fmt.Sprintf("could not convert timestamp %s to time.time", timestamp))
+			logging.Error(fmt.Errorf("could not convert timestamp %s to time.time: ", timestamp, err.Error()))
 			return time.Time{}, false
 		}
 		return tm, true
@@ -132,10 +132,10 @@ func scaleDeployments() {
 		currentAvailableReplicas, availableReplicasErr := prometheus.ReadCurrentPrometheusMetricValue(&configuration.ActiveConfiguration, fmt.Sprintf("kube_deployment_status_replicas_available{functionname=\"%s\"}", function.Name))
 		requiredContainers, requiredContainersErr := prometheus.ReadCurrentPrometheusMetricValue(&configuration.ActiveConfiguration, fmt.Sprintf("job:function_containers_required:containers{functionname=\"%s\"} or vector(0)", function.Name))
 		if availableReplicasErr != nil {
-			logging.Error("there was an error when trying to read metric [kube_deployment_status_replicas_available]. setting result-scale to 0")
+			logging.Error(fmt.Errorf("there was an error when trying to read metric [kube_deployment_status_replicas_available]. setting result-scale to 0: %s", availableReplicasErr.Error()))
 			resultScale = 0
 		} else if requiredContainersErr != nil {
-			logging.Error("there was an error when trying to read metric [job:function_containers_required:containers]. setting result-scale to 0")
+			logging.Error(fmt.Errorf("there was an error when trying to read metric [job:function_containers_required:containers]. setting result-scale to 0: %s", requiredContainersErr.Error()))
 			resultScale = 0
 		} else {
 			resultScale = int(math.Ceil(requiredContainers))
@@ -146,8 +146,8 @@ func scaleDeployments() {
 		// get current inflight requests of function
 		target, err := f2shub.F2SDispatcherHub.GetDispatcherFunctionByName(function.Name)
 		if err != nil {
-			logging.Error(fmt.Sprintf("%s", err))
-			logging.Error(fmt.Sprintf("[scaling] could not get function target for function-name: %s. skipping scaling of this function...", function.Name))
+			logging.Error(fmt.Errorf("could not GetDispatcherFunctionByName: %s", err.Error()))
+			logging.Error(fmt.Errorf("[scaling] could not get function target for function-name: %s. skipping scaling of this function...", function.Name))
 			continue
 		}
 		numInflightRequests := target.GetTotalInflightRequests()

f2soperator/operation/operator/eventhandler.go

@@ -36,7 +36,7 @@ func checkMinimumAvailability(function *v1alpha1types.PrettyFunction) {
 	logging.Info("[checkMinimumAvailability] checking minimum availability")
 	target, err := f2shub.F2SDispatcherHub.GetDispatcherFunctionByName(function.Name)
 	if err != nil {
-		logging.Error(fmt.Sprintf("[checkMinimumAvailability] could not get target for function %s. %s", function.Name, err.Error()))
+		logging.Error(fmt.Errorf("[checkMinimumAvailability] could not get target for function %s. %s", function.Name, err.Error()))
 		return
 	}
 	if len(target.ServingPods) == 0 {
@@ -92,8 +92,7 @@ func OnF2SEndpointsChanged(obj interface{}) {
 	err := runtime.DefaultUnstructuredConverter.
 		FromUnstructured(obj.(*unstructured.Unstructured).UnstructuredContent(), d)
 	if err != nil {
-		logging.Error(fmt.Sprintf("could not convert event to endpoint"))
-		logging.Error(fmt.Sprintf("%s", err))
+		logging.Error(fmt.Errorf("OnF2SEndpointsChanged: could not convert event to endpoint: %s", err.Error()))
 		return
 	}
 

f2soperator/operation/operator/main.go

@@ -73,8 +73,7 @@ func CheckMaster() (bool, error) {
 	logging.Debug("[check master] reading prometheus metric 'f2s_master_election_ready_pods'")
 	result, err := prometheus.ReadPrometheusMetric(&configuration.ActiveConfiguration, "f2s_master_election_ready_pods")
 	if err != nil {
-		logging.Error(fmt.Sprintf("%s", err))
-		logging.Error(fmt.Sprintf("[check master] prometheus seems not to be reachable. prometheus URL can also specified by 'export Prometheus_URL=localhost:9090'"))
+		logging.Error(fmt.Errorf("[check master] prometheus seems not to be reachable. prometheus URL can also specified by 'export Prometheus_URL=localhost:9090'"))
 	}
 
 	// get all f2s replica uid's

f2soperator/services/kubernetes/deployments.go

@@ -143,7 +143,7 @@ func DeleteDeployment(uid string) error {
 			err = clientset.AppsV1().Deployments("f2s-containers").Delete(context.Background(), d.Name, metav1.DeleteOptions{})
 
 			if err != nil {
-				logging.Error(fmt.Sprintf("error during deletion: %s", err))
+				logging.Error(fmt.Errorf("[DeleteDeployment] error during deletion: %s", err))
 			}
 
 			return nil

f2soperator/services/kubernetes/f2sfunctions.go

@@ -16,7 +16,7 @@ func GetF2SFunctions() (*typesV1alpha1.FunctionList, error) {
 	logging.Info("initializing k8s clientset")
 	clientSet, err := GetV1Alpha1ClientSet()
 	if err != nil {
-		logging.Error(fmt.Sprintf("error during clientset initialisation: %s", err))
+		logging.Error(fmt.Errorf("[GetF2SFunctions] error during clientset initialisation: %s", err.Error()))
 		panic(err)
 	}
 
@@ -37,7 +37,7 @@ func CreateF2SFunction(prettyFunction *typesV1alpha1.PrettyFunction) (*typesV1al
 	logging.Info("initializing k8s clientset")
 	clientSet, err := GetV1Alpha1ClientSet()
 	if err != nil {
-		logging.Error(fmt.Sprintf("error during clientset initialisation: %s", err))
+		logging.Error(fmt.Errorf("[CreateF2SFunction] error during clientset initialisation: %s", err.Error()))
 		panic(err)
 	}
 
@@ -64,7 +64,7 @@ func CreateF2SFunction(prettyFunction *typesV1alpha1.PrettyFunction) (*typesV1al
 	logging.Info("creating function in k8s")
 	function, err := clientSet.Functions("f2s").Create(newFunction)
 	if err != nil {
-		logging.Error(fmt.Sprintf("error during function creation: %s", err))
+		logging.Error(fmt.Errorf("[CreateF2SFunction] error during function creation: %s", err.Error()))
 		log.Fatal(err)
 	}
 
@@ -79,15 +79,15 @@ func DeleteF2SFunction(uid string) error {
 	logging.Info("initializing k8s clientset")
 	clientSet, err := GetV1Alpha1ClientSet()
 	if err != nil {
-		logging.Error(fmt.Sprintf("error during clientset initialisation: %s", err))
+		logging.Error(fmt.Errorf("[DeleteF2SFunction] error during clientset initialisation: %s", err.Error()))
 		panic(err)
 	}
 
 	logging.Info("deleting f2sfunction in k8s")
 	err = clientSet.Functions("f2s").Delete(uid, metav1.DeleteOptions{})
 
 	if err != nil {
-		logging.Error(fmt.Sprintf("error during deletion: %s", err))
+		logging.Error(fmt.Errorf("[DeleteF2SFunction] error during deletion: %s", err.Error()))
 	}
 
 	return err

f2soperator/services/kubernetes/kubernetes.go

@@ -38,8 +38,8 @@ func GetV1Alpha1ClientSet() (*clientV1alpha1.V1Alpha1Client, error) {
 	// Retrieve the in-cluster configuration
 	config, err := getInClusterConfig()
 	if err != nil {
-		logging.Error(fmt.Sprintf("Failed to get in-cluster config: %s\n", err))
-		logging.Error(fmt.Sprintf("you can use env variable 'export KUBECONFIG=~/.kube/config' to specify a local config file"))
+		logging.Error(fmt.Errorf("[GetV1Alpha1ClientSet] Failed to get in-cluster config: %s\n", err.Error()))
+		logging.Error(fmt.Errorf("[GetV1Alpha1ClientSet] you can use env variable 'export KUBECONFIG=~/.kube/config' to specify a local config file"))
 		os.Exit(1)
 	}
 
@@ -57,8 +57,8 @@ func GetV1ClientSet() (*k8s.Clientset, error) {
 	// Retrieve the in-cluster configuration
 	config, err := getInClusterConfig()
 	if err != nil {
-		logging.Error(fmt.Sprintf("Failed to get in-cluster config: %s\n", err))
-		logging.Error(fmt.Sprintf("you can use env variable 'export KUBECONFIG=~/.kube/config' to specify a local config file"))
+		logging.Error(fmt.Errorf("[GetV1ClientSet] Failed to get in-cluster config: %s\n", err.Error()))
+		logging.Error(fmt.Errorf("[GetV1ClientSet] you can use env variable 'export KUBECONFIG=~/.kube/config' to specify a local config file"))
 		os.Exit(1)
 	}
 

f2soperator/services/kubernetes/services.go

@@ -79,7 +79,7 @@ func DeleteService(uid string) error {
 			err = clientset.CoreV1().Services("f2s-containers").Delete(context.Background(), d.Name, metav1.DeleteOptions{})
 
 			if err != nil {
-				logging.Error(fmt.Sprintf("error during deletion: %s", err))
+				logging.Error(fmt.Errorf("[DeleteService] error during deletion: %s", err.Error()))
 			}
 
 			return nil

f2soperator/services/kubernetes/watch.go

@@ -52,7 +52,7 @@ func runCRDInformer(stopCh <-chan struct{}, s cache.SharedIndexInformer, callbac
 func GetDynamicInformer(resource string, namespace string) (informers.GenericInformer, error) {
 	cfg, err := getInClusterConfig()
 	if err != nil {
-		logging.Error(fmt.Sprintf("Failed to get in-cluster config: %s\n", err.Error()))
+		logging.Error(fmt.Errorf("[GetDynamicInformer] Failed to get in-cluster config: %s\n", err.Error()))
 		os.Exit(1)
 	}
 

f2soperator/services/logger/logging.go

@@ -30,8 +30,8 @@ func (l F2SLogger) Debug(text ...string) {
 func (l F2SLogger) Warn(text ...string) {
 	l.Logger.Warn(strings.Join(text, " "), "type", "log")
 }
-func (l F2SLogger) Error(text ...string) {
-	l.Logger.Error(strings.Join(text, " "), "type", "log")
+func (l F2SLogger) Error(err error) {
+	l.Logger.Error(err.Error(), "type", "log")
 }
 
 // log an event