feat(controller): add timimg http header responses

Signed-off-by: AlexandreBrg <burgoni@pm.me>

controller/api/handlers/invoke-function.go

@@ -25,7 +25,8 @@ var (
 
 func InvokeFunctionHandler(s state.State, orch orchestration.Orchestrator) gin.HandlerFunc {
 	return func(c *gin.Context) {
-		start := time.Now()
+		// Start the analytics
+		analytics := NewInvokeAnalytics()
 		ctx, fnName, fnVersion := c.Request.Context(), c.Param("name"), c.Param("version")
 
 		log.Debugf("Invoke version '%s' of function '%s'", fnVersion, fnName)
@@ -71,6 +72,7 @@ func InvokeFunctionHandler(s state.State, orch orchestration.Orchestrator) gin.H
 			log.Infof("Function '%s' is healthy and ready to receive requests", fnName)
 			break
 		}
+		analytics.UpsertOrchestrate()
 
 		// Each invocation warn up function for 15 minutes
 		if err := s.SetWithExpiry(ctx, instance.Id, 15*time.Minute); err != nil {
@@ -85,7 +87,7 @@ func InvokeFunctionHandler(s state.State, orch orchestration.Orchestrator) gin.H
 
 		proxy.ModifyResponse = func(r *http.Response) error {
 			// Record the execution time of the invocation
-			elapsed := time.Since(start).Seconds()
+			elapsed := float64(analytics.UpsertInvoke()) / 1000
 			log.Debugf("Function '%s' was invoked in %vs (is cold start: %v)", fnName, elapsed, isColdStart)
 			telemetry.FunctionInvocationDurationHistogram.WithLabelValues(labels...).Observe(elapsed)
 
@@ -119,6 +121,10 @@ func InvokeFunctionHandler(s state.State, orch orchestration.Orchestrator) gin.H
 			r.ContentLength = int64(contentLength)
 			r.Header.Set("Content-Length", strconv.Itoa(contentLength))
 
+			r.Header.Set(string(HttpHeaderFunctionResponseTime), strconv.FormatInt(analytics.UpsertInvoke(), 10))
+			r.Header.Set(string(HttpHeaderOrchestrateResponseTime), strconv.FormatInt(analytics.UpsertOrchestrate(), 10))
+			r.Header.Set(string(HttpHeaderMortyResponseTime), strconv.FormatInt(analytics.UpsertTotal(), 10))
+
 			return nil
 		}
 

controller/api/handlers/types.go

@@ -1,5 +1,21 @@
 package handlers
 
+import "time"
+
+type CustomHttpHeader string
+
+const (
+	// Function-Response-Time
+	// ref: https://github.com/morty-faas/morty/issues/25
+	HttpHeaderFunctionResponseTime CustomHttpHeader = "Function-Response-Time"
+	// Orchestrate-Response-Time
+	// ref: https://github.com/morty-faas/morty/issues/25
+	HttpHeaderOrchestrateResponseTime CustomHttpHeader = "Orchestrate-Response-Time"
+	// Morty-Response-Time
+	// ref: https://github.com/morty-faas/morty/issues/25
+	HttpHeaderMortyResponseTime CustomHttpHeader = "Morty-Response-Time"
+)
+
 type APIError struct {
 	Message string `json:"message"`
 }
@@ -9,3 +25,54 @@ func makeApiError(err error) *APIError {
 		Message: err.Error(),
 	}
 }
+
+// InvokeAnalytics contains few information about the function invocation, it can be used for debugging purposes
+// and for benchmarking
+type InvokeAnalytics struct {
+	start time.Time
+	// Total is the total time spent in the function handler, from the moment the request is received until the
+	// response is sent back to the client
+	total int64
+	// Orchestrate is the time spent in the orchestration layer, from the moment the request is received until the
+	// function is deployed and ready to be invoked
+	orchestrate int64
+	// Invoke is the time spent in the function handler, from the moment the function is invoked until the response
+	// is sent back to the client
+	invoke int64
+}
+
+func NewInvokeAnalytics() *InvokeAnalytics {
+	return &InvokeAnalytics{
+		start: time.Now(),
+	}
+}
+
+// UpsertOrchestrate returns the time spent in the orchestration layer, in milliseconds. If the value is not set, it will
+// be calculated else it will return a cached value.
+func (i *InvokeAnalytics) UpsertOrchestrate() int64 {
+	if i.orchestrate != 0 {
+		return i.orchestrate
+	}
+	i.orchestrate = time.Since(i.start).Milliseconds()
+	return i.orchestrate
+}
+
+// UpsertInvoke returns the time spent in for the invoke, in milliseconds. If the value is not set, it will be calculated
+// else it will return a cached value.
+func (i *InvokeAnalytics) UpsertInvoke() int64 {
+	if i.invoke != 0 {
+		return i.invoke
+	}
+	i.invoke = time.Since(i.start).Milliseconds() - i.UpsertOrchestrate()
+	return i.invoke
+}
+
+// UpsertTotal returns the total time spent in the function handler, in milliseconds. If it's the first call to this
+// method, it will register the time spent since start and return it, otherwise it will return the cached value.
+func (i *InvokeAnalytics) UpsertTotal() int64 {
+	if i.total != 0 {
+		return i.total
+	}
+	i.total = time.Since(i.start).Milliseconds()
+	return i.total
+}