Add metrics to Reaper (#2019)

* Add metrics to Reaper

Signed-off-by: Harsh Thakur <harshthakur9030@gmail.com>

* Change duration to seconds and fix labels

Signed-off-by: Harsh Thakur <harshthakur9030@gmail.com>

go.mod

@@ -38,7 +38,6 @@ require (
 	github.com/marstr/guid v1.1.0 // indirect
 	github.com/mholt/archiver v0.0.0-20180417220235-e4ef56d48eb0
 	github.com/minio/minio-go v6.0.14+incompatible
-	github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822
 	github.com/nats-io/nats-streaming-server v0.17.0
 	github.com/nats-io/nats.go v1.9.1
 	github.com/nats-io/stan.go v0.6.0
@@ -58,7 +57,6 @@ require (
 	github.com/wcharczuk/go-chart v2.0.1+incompatible
 	go.opencensus.io v0.22.4
 	go.uber.org/zap v1.10.0
-	golang.org/x/exp v0.0.0-20200224162631-6cc2880d07d6 // indirect
 	golang.org/x/net v0.0.0-20201202161906-c7110b5ffcbb
 	golang.org/x/time v0.0.0-20200630173020-3af7569d3a1e // indirect
 	gopkg.in/jcmturner/goidentity.v3 v3.0.0 // indirect
@@ -67,6 +65,5 @@ require (
 	k8s.io/apimachinery v0.17.2
 	k8s.io/client-go v0.17.2
 	k8s.io/klog v1.0.0
-	k8s.io/klog/v2 v2.8.0
 	k8s.io/metrics v0.17.2
 )

go.sum

@@ -224,8 +224,6 @@ github.com/go-kit/kit v0.9.0/go.mod h1:xBxKIO96dXMWWy0MnWVtmwkA9/13aqxPnvrjFYMA2
 github.com/go-logfmt/logfmt v0.3.0/go.mod h1:Qt1PoO58o5twSAckw1HlFXLmHsOX5/0LbT9GBnD5lWE=
 github.com/go-logfmt/logfmt v0.4.0/go.mod h1:3RMwSq7FuexP4Kalkev3ejPJsZTpXXBr9+V4qmtdjCk=
 github.com/go-logr/logr v0.1.0/go.mod h1:ixOQHD9gLJUVQQ2ZOR7zLEifBX6tGkNJF4QyIY7sIas=
-github.com/go-logr/logr v0.4.0 h1:K7/B1jt6fIBQVd4Owv2MqGQClcgf0R266+7C/QjRcLc=
-github.com/go-logr/logr v0.4.0/go.mod h1:z6/tIYblkpsD+a4lm/fGIIU9mZ+XfAiaFtq7xTgseGU=
 github.com/go-openapi/analysis v0.0.0-20180825180245-b006789cd277/go.mod h1:k70tL6pCuVxPJOHXQ+wIac1FUrvNkHolPie/cLEU6hI=
 github.com/go-openapi/analysis v0.17.0/go.mod h1:IowGgpVeD0vNm45So8nr+IcQ3pxVtpRoBWb8PVZO0ik=
 github.com/go-openapi/analysis v0.18.0/go.mod h1:IowGgpVeD0vNm45So8nr+IcQ3pxVtpRoBWb8PVZO0ik=
@@ -1154,8 +1152,6 @@ k8s.io/klog v0.0.0-20181102134211-b9b56d5dfc92/go.mod h1:Gq+BEi5rUBO/HRz0bTSXDUc
 k8s.io/klog v0.3.0/go.mod h1:Gq+BEi5rUBO/HRz0bTSXDUcqjScdoY3a9IHpCEIOOfk=
 k8s.io/klog v1.0.0 h1:Pt+yjF5aB1xDSVbau4VsWe+dQNzA0qv1LlXdC2dF6Q8=
 k8s.io/klog v1.0.0/go.mod h1:4Bi6QPql/J/LkTDqv7R/cd3hPo4k2DG6Ptcz060Ez5I=
-k8s.io/klog/v2 v2.8.0 h1:Q3gmuM9hKEjefWFFYF0Mat+YyFJvsUyYuwyNNJ5C9Ts=
-k8s.io/klog/v2 v2.8.0/go.mod h1:hy9LJ/NvuK+iVyP4Ehqva4HxZG/oXyIS3n3Jmire4Ec=
 k8s.io/kube-openapi v0.0.0-20191107075043-30be4d16710a h1:UcxjrRMyNx/i/y8G7kPvLyy7rfbeuf1PYyBf973pgyU=
 k8s.io/kube-openapi v0.0.0-20191107075043-30be4d16710a/go.mod h1:1TqjTSzOxsLGIKfj0lK8EeCP7K1iUG65v09OM0/WG5E=
 k8s.io/metrics v0.17.2 h1:cuN1ScyUS9/tj4YFI8d0/7yO0BveFHhyQpPNWS8uLr8=

pkg/executor/executortype/newdeploy/newdeploymgr.go

@@ -845,7 +845,10 @@ func (deploy *NewDeploy) idleObjectReaper() {
 				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))
@@ -870,6 +873,7 @@ func (deploy *NewDeploy) idleObjectReaper() {
 				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/gpm.go

@@ -669,8 +669,11 @@ 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(fsvc, idlePodReapTime)
 				if err != nil {
 					gpm.logger.Error("error deleting Kubernetes objects for function service",
@@ -687,6 +690,7 @@ func (gpm *GenericPoolManager) idleObjectReaper() {
 						)
 						reaper.CleanupKubeObject(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/metrics.go

@@ -37,6 +37,22 @@ var (
 		},
 		[]string{"funcname", "funcuid"},
 	)
+	funcReapTime = prometheus.NewSummaryVec(
+		prometheus.SummaryOpts{
+			Name:       "fission_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},
+		},
+		[]string{"funcname", "funcaddress"},
+	)
+	idleTime = prometheus.NewSummaryVec(
+		prometheus.SummaryOpts{
+			Name:       "fission_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},
+		},
+		[]string{"funcname", "funcaddress"},
+	)
 )
 
 func init() {
@@ -45,6 +61,8 @@ func init() {
 	prometheus.MustRegister(funcRunningSummary)
 	prometheus.MustRegister(funcAliveSummary)
 	prometheus.MustRegister(funcIsAlive)
+	prometheus.MustRegister(funcReapTime)
+	prometheus.MustRegister(idleTime)
 }
 
 // IncreaseColdStarts increments the counter by 1.
@@ -67,3 +85,13 @@ func (fsc *FunctionServiceCache) setFuncAlive(funcname, funcuid string, isAlive
 	}
 	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(float64(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)
+}