Prometheus metrics improvements (#2398)

- Enabled metrics in storagesvc, buildermgr and controller.
- Added a middleware in storagesvc, router, executor and controller to monitor total number of http requests, each request's duration and number of requests that are currently being served. These requests can be filtered on their path, method or statuscode.
- Removed functionCallDuration and functionCallResponseSize metrics from router.
- Removed funcAliveSummary, funcIsAlive, funcReapTime and idleTime metrics.
- Replaced function calls for collecting metrics to direct metric calls.

Signed-off-by: Sanket Sudake <sanketsudake@gmail.com>
Co-authored-by: Sanket Sudake <sanketsudake@gmail.com>

pkg/executor/api.go

@@ -34,6 +34,7 @@ import (
 	fv1 "github.com/fission/fission/pkg/apis/core/v1"
 	ferror "github.com/fission/fission/pkg/error"
 	"github.com/fission/fission/pkg/executor/client"
+	"github.com/fission/fission/pkg/utils/metrics"
 	otelUtils "github.com/fission/fission/pkg/utils/otel"
 )
 
@@ -251,6 +252,7 @@ func (executor *Executor) unTapService(w http.ResponseWriter, r *http.Request) {
 // GetHandler returns an http.Handler.
 func (executor *Executor) GetHandler() http.Handler {
 	r := mux.NewRouter()
+	r.Use(metrics.HTTPMetricMiddleware())
 	r.HandleFunc("/v2/getServiceForFunction", executor.getServiceForFunctionAPI).Methods("POST")
 	r.HandleFunc("/v2/tapService", executor.tapService).Methods("POST") // for backward compatibility
 	r.HandleFunc("/v2/tapServices", executor.tapServices).Methods("POST")

pkg/executor/executor.go

@@ -19,7 +19,6 @@ package executor
 import (
 	"context"
 	"fmt"
-	"net/http"
 	"os"
 	"strconv"
 	"strings"
@@ -28,7 +27,6 @@ import (
 
 	"github.com/dchest/uniuri"
 	"github.com/pkg/errors"
-	"github.com/prometheus/client_golang/prometheus/promhttp"
 	"go.uber.org/zap"
 	k8sInformers "k8s.io/client-go/informers"
 	k8sCache "k8s.io/client-go/tools/cache"
@@ -46,6 +44,7 @@ import (
 	fetcherConfig "github.com/fission/fission/pkg/fetcher/config"
 	genInformer "github.com/fission/fission/pkg/generated/informers/externalversions"
 	"github.com/fission/fission/pkg/utils"
+	"github.com/fission/fission/pkg/utils/metrics"
 	otelUtils "github.com/fission/fission/pkg/utils/otel"
 )
 
@@ -250,15 +249,6 @@ func (executor *Executor) getFunctionServiceFromCache(ctx context.Context, fn *f
 	return e.GetFuncSvcFromCache(ctx, fn)
 }
 
-func serveMetric(logger *zap.Logger) {
-	// Expose the registered metrics via HTTP.
-	metricAddr := ":8080"
-	http.Handle("/metrics", promhttp.Handler())
-	err := http.ListenAndServe(metricAddr, nil)
-
-	logger.Fatal("done listening on metrics endpoint", zap.Error(err))
-}
-
 // StartExecutor Starts executor and the executor components such as Poolmgr,
 // deploymgr and potential future executor types
 func StartExecutor(ctx context.Context, logger *zap.Logger, functionNamespace string, envBuilderNamespace string, port int, openTracingEnabled bool) error {
@@ -379,8 +369,8 @@ func StartExecutor(ctx context.Context, logger *zap.Logger, functionNamespace st
 		return err
 	}
 	go reaper.CleanupRoleBindings(ctx, logger, kubernetesClient, fissionClient, functionNamespace, envBuilderNamespace, time.Minute*30)
+	go metrics.ServeMetrics(ctx, logger)
 	go api.Serve(port, openTracingEnabled)
-	go serveMetric(logger)
 
 	return nil
 }

pkg/executor/executortype/container/containermgr.go

@@ -45,6 +45,7 @@ import (
 	"github.com/fission/fission/pkg/crd"
 	"github.com/fission/fission/pkg/executor/executortype"
 	"github.com/fission/fission/pkg/executor/fscache"
+	"github.com/fission/fission/pkg/executor/metrics"
 	"github.com/fission/fission/pkg/executor/reaper"
 	finformerv1 "github.com/fission/fission/pkg/generated/informers/externalversions/core/v1"
 	"github.com/fission/fission/pkg/throttler"
@@ -440,10 +441,11 @@ func (caaf *Container) fnCreate(ctx context.Context, fn *fv1.Function) (*fscache
 	_, err = caaf.fsCache.Add(*fsvc)
 	if err != nil {
 		caaf.logger.Error("error adding function to cache", zap.Error(err), zap.Any("function", fsvc.Function))
+		metrics.FuncError.WithLabelValues(fn.ObjectMeta.Name, fn.ObjectMeta.Namespace).Inc()
 		return fsvc, err
 	}
 
-	caaf.fsCache.IncreaseColdStarts(fn.ObjectMeta.Name, string(fn.ObjectMeta.UID))
+	metrics.ColdStarts.WithLabelValues(fn.ObjectMeta.Name, fn.ObjectMeta.Namespace).Inc()
 
 	return fsvc, nil
 }

pkg/executor/executortype/newdeploy/newdeploymgr.go

@@ -45,6 +45,7 @@ import (
 	"github.com/fission/fission/pkg/crd"
 	"github.com/fission/fission/pkg/executor/executortype"
 	"github.com/fission/fission/pkg/executor/fscache"
+	"github.com/fission/fission/pkg/executor/metrics"
 	"github.com/fission/fission/pkg/executor/reaper"
 	fetcherConfig "github.com/fission/fission/pkg/fetcher/config"
 	finformerv1 "github.com/fission/fission/pkg/generated/informers/externalversions/core/v1"
@@ -480,10 +481,11 @@ func (deploy *NewDeploy) fnCreate(ctx context.Context, fn *fv1.Function) (*fscac
 	_, err = deploy.fsCache.Add(*fsvc)
 	if err != nil {
 		deploy.logger.Error("error adding function to cache", zap.Error(err), zap.Any("function", fsvc.Function))
+		metrics.FuncError.WithLabelValues(fn.ObjectMeta.Name, fn.ObjectMeta.Namespace).Inc()
 		return fsvc, err
 	}
 
-	deploy.fsCache.IncreaseColdStarts(fn.ObjectMeta.Name, string(fn.ObjectMeta.UID))
+	metrics.ColdStarts.WithLabelValues(fn.ObjectMeta.Name, fn.ObjectMeta.Namespace).Inc()
 
 	return fsvc, nil
 }
@@ -804,10 +806,7 @@ func (deploy *NewDeploy) idleObjectReaper(ctx context.Context) {
 				continue
 			}
 
-			deploy.fsCache.IdleTime(fsvc.Name, fsvc.Address, float64(time.Since(fsvc.Atime)-idlePodReapTime))
-
 			go func() {
-				startTime := time.Now()
 				deployObj := getDeploymentObj(fsvc.KubernetesObjects)
 				if deployObj == nil {
 					deploy.logger.Error("error finding function deployment", zap.Error(err), zap.String("function", fsvc.Function.Name))
@@ -832,7 +831,6 @@ func (deploy *NewDeploy) idleObjectReaper(ctx context.Context) {
 				if err != nil {
 					deploy.logger.Error("error scaling down function deployment", zap.Error(err), zap.String("function", fsvc.Function.Name))
 				}
-				deploy.fsCache.ReapTime(fsvc.Function.Name, fsvc.Address, time.Since(startTime).Seconds())
 			}()
 		}
 	}

pkg/executor/executortype/poolmgr/gp.go

@@ -46,6 +46,7 @@ import (
 	fv1 "github.com/fission/fission/pkg/apis/core/v1"
 	"github.com/fission/fission/pkg/crd"
 	"github.com/fission/fission/pkg/executor/fscache"
+	"github.com/fission/fission/pkg/executor/metrics"
 	fetcherClient "github.com/fission/fission/pkg/fetcher/client"
 	fetcherConfig "github.com/fission/fission/pkg/fetcher/config"
 	"github.com/fission/fission/pkg/utils"
@@ -583,7 +584,7 @@ func (gp *GenericPool) getFuncSvc(ctx context.Context, fn *fv1.Function) (*fscac
 	gp.podFSVCMap.Store(pod.ObjectMeta.Name, []interface{}{crd.CacheKey(fsvc.Function), fsvc.Address})
 	gp.fsCache.AddFunc(ctx, *fsvc)
 
-	gp.fsCache.IncreaseColdStarts(fn.ObjectMeta.Name, string(fn.ObjectMeta.UID))
+	metrics.ColdStarts.WithLabelValues(fn.ObjectMeta.Name, fn.ObjectMeta.Namespace).Inc()
 
 	logger.Info("added function service",
 		zap.String("pod", pod.ObjectMeta.Name),

pkg/executor/executortype/poolmgr/gpm.go

@@ -631,11 +631,8 @@ func (gpm *GenericPoolManager) idleObjectReaper() {
 			if time.Since(fsvc.Atime) < idlePodReapTime {
 				continue
 			}
-			idleTime := (time.Since(fsvc.Atime) - idlePodReapTime).Seconds()
-			gpm.fsCache.IdleTime(fsvc.Name, fsvc.Address, idleTime)
 
 			go func() {
-				startTime := time.Now()
 				deleted, err := gpm.fsCache.DeleteOldPoolCache(ctx, fsvc, idlePodReapTime)
 				if err != nil {
 					gpm.logger.Error("error deleting Kubernetes objects for function service",
@@ -652,7 +649,6 @@ func (gpm *GenericPoolManager) idleObjectReaper() {
 						)
 						reaper.CleanupKubeObject(ctx, gpm.logger, gpm.kubernetesClient, &fsvc.KubernetesObjects[i])
 						time.Sleep(50 * time.Millisecond)
-						gpm.fsCache.ReapTime(fsvc.Function.Name, fsvc.Address, time.Since(startTime).Seconds())
 					}
 				}
 			}()

pkg/executor/fscache/functionServiceCache.go

@@ -34,6 +34,7 @@ import (
 	"github.com/fission/fission/pkg/cache"
 	"github.com/fission/fission/pkg/crd"
 	ferror "github.com/fission/fission/pkg/error"
+	"github.com/fission/fission/pkg/executor/metrics"
 	"github.com/fission/fission/pkg/poolcache"
 )
 
@@ -227,8 +228,6 @@ func (fsc *FunctionServiceCache) AddFunc(ctx context.Context, fsvc FuncSvc) {
 	now := time.Now()
 	fsvc.Ctime = now
 	fsvc.Atime = now
-
-	fsc.setFuncAlive(fsvc.Function.Name, string(fsvc.Function.UID), true)
 }
 
 // SetCPUUtilizaton updates/sets CPUutilization in the pool cache
@@ -284,7 +283,6 @@ func (fsc *FunctionServiceCache) Add(fsvc FuncSvc) (*FuncSvc, error) {
 		return nil, err
 	}
 
-	fsc.setFuncAlive(fsvc.Function.Name, string(fsvc.Function.UID), true)
 	return nil, nil
 }
 
@@ -345,9 +343,7 @@ func (fsc *FunctionServiceCache) DeleteEntry(fsvc *FuncSvc) {
 		)
 	}
 
-	fsc.observeFuncRunningTime(fsvc.Function.Name, string(fsvc.Function.UID), fsvc.Atime.Sub(fsvc.Ctime).Seconds())
-	fsc.observeFuncAliveTime(fsvc.Function.Name, string(fsvc.Function.UID), time.Since(fsvc.Ctime).Seconds())
-	fsc.setFuncAlive(fsvc.Function.Name, string(fsvc.Function.UID), false)
+	metrics.FuncRunningSummary.WithLabelValues(fsvc.Function.Name, fsvc.Function.Namespace).Observe(fsvc.Atime.Sub(fsvc.Ctime).Seconds())
 }
 
 // DeleteFunctionSvc deletes a function service at key composed of [function][address].

pkg/executor/fscache/metrics.go

@@ -1,100 +0,0 @@
-package fscache
-
-import (
-	"github.com/prometheus/client_golang/prometheus"
-)
-
-var (
-	// function_name: the function's name
-	// function_uid: the function's version id
-	// function_address: the address of the pod from which the function was called
-	functionLabels    = []string{"function_name", "function_uid"}
-	functionPodLabels = []string{"function_name", "function_address"}
-	coldStarts        = prometheus.NewCounterVec(
-		prometheus.CounterOpts{
-			Name: "fission_function_cold_starts_total",
-			Help: "How many cold starts are made by function_name, function_uid.",
-		},
-		functionLabels,
-	)
-	funcRunningSummary = prometheus.NewSummaryVec(
-		prometheus.SummaryOpts{
-			Name:       "fission_function_running_seconds",
-			Help:       "The running time (last access - create) in seconds of the function.",
-			Objectives: map[float64]float64{0.5: 0.05, 0.9: 0.01, 0.99: 0.001},
-		},
-		functionLabels,
-	)
-	funcAliveSummary = prometheus.NewSummaryVec(
-		prometheus.SummaryOpts{
-			Name:       "fission_function_alive_seconds",
-			Help:       "The alive time in seconds of the function.",
-			Objectives: map[float64]float64{0.5: 0.05, 0.9: 0.01, 0.99: 0.001},
-		},
-		functionLabels,
-	)
-	funcIsAlive = prometheus.NewGaugeVec(
-		prometheus.GaugeOpts{
-			Name: "fission_function_is_alive",
-			Help: "A binary value indicating is the function_name, function_uid alive",
-		},
-		functionLabels,
-	)
-	funcReapTime = prometheus.NewSummaryVec(
-		prometheus.SummaryOpts{
-			Name:       "fission_function_pod_reaptime_seconds",
-			Help:       "Amount of seconds to reap a pod",
-			Objectives: map[float64]float64{0.5: 0.05, 0.9: 0.01, 0.99: 0.001},
-		},
-		functionPodLabels,
-	)
-	idleTime = prometheus.NewSummaryVec(
-		prometheus.SummaryOpts{
-			Name:       "fission_function_idle_pod_time",
-			Help:       "Number of seconds it took for Reaper to detect the pod was idle",
-			Objectives: map[float64]float64{0.5: 0.05, 0.9: 0.01, 0.99: 0.001},
-		},
-		functionPodLabels,
-	)
-)
-
-func init() {
-	// Register the function calls counter with Prometheus's default registry.
-	prometheus.MustRegister(coldStarts)
-	prometheus.MustRegister(funcRunningSummary)
-	prometheus.MustRegister(funcAliveSummary)
-	prometheus.MustRegister(funcIsAlive)
-	prometheus.MustRegister(funcReapTime)
-	prometheus.MustRegister(idleTime)
-}
-
-// IncreaseColdStarts increments the counter by 1.
-func (fsc *FunctionServiceCache) IncreaseColdStarts(funcname, funcuid string) {
-	coldStarts.WithLabelValues(funcname, funcuid).Inc()
-}
-
-func (fsc *FunctionServiceCache) observeFuncRunningTime(funcname, funcuid string, running float64) {
-	funcRunningSummary.WithLabelValues(funcname, funcuid).Observe(running)
-}
-
-func (fsc *FunctionServiceCache) observeFuncAliveTime(funcname, funcuid string, alive float64) {
-	funcAliveSummary.WithLabelValues(funcname, funcuid).Observe(alive)
-}
-
-func (fsc *FunctionServiceCache) setFuncAlive(funcname, funcuid string, isAlive bool) {
-	count := 0
-	if isAlive {
-		count = 1
-	}
-	funcIsAlive.WithLabelValues(funcname, funcuid).Set(float64(count))
-}
-
-// ReapTime is the amount of time taken to reap a pod
-func (fsc *FunctionServiceCache) ReapTime(funcName, funcAddress string, time float64) {
-	funcReapTime.WithLabelValues(funcName, funcAddress).Observe(time)
-}
-
-// IdleTime is the amount of time it took Reaper to find out the pod was idle
-func (fsc *FunctionServiceCache) IdleTime(funcName, funcAddress string, time float64) {
-	idleTime.WithLabelValues(funcName, funcAddress).Observe(time)
-}

pkg/executor/metrics/metrics.go

@@ -0,0 +1,51 @@
+/*
+Copyright 2022 The Fission Authors.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+    http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+*/
+
+package metrics
+
+import (
+	"github.com/prometheus/client_golang/prometheus"
+	"github.com/prometheus/client_golang/prometheus/promauto"
+)
+
+var (
+	// function_name: the function's name
+	// function_uid: the function's version id
+	// function_address: the address of the pod from which the function was called
+	functionLabels = []string{"function_name", "function_namespace"}
+	ColdStarts     = promauto.NewCounterVec(
+		prometheus.CounterOpts{
+			Name: "fission_function_cold_starts_total",
+			Help: "How many cold starts are made by function_name, function_uid.",
+		},
+		functionLabels,
+	)
+	FuncRunningSummary = promauto.NewSummaryVec(
+		prometheus.SummaryOpts{
+			Name:       "fission_function_running_seconds",
+			Help:       "The running time (last access - create) in seconds of the function.",
+			Objectives: map[float64]float64{0.5: 0.05, 0.9: 0.01, 0.99: 0.001},
+		},
+		functionLabels,
+	)
+	FuncError = promauto.NewCounterVec(
+		prometheus.CounterOpts{
+			Name: "fission_function_cold_start_errors_total",
+			Help: "Count of fission cold start errors",
+		},
+		functionLabels,
+	)
+)