Add request metrics for BBS

cmd/bbs/main.go

@@ -39,6 +39,7 @@ import (
 	"code.cloudfoundry.org/locket/jointlock"
 	"code.cloudfoundry.org/locket/lock"
 	"code.cloudfoundry.org/locket/lockheldmetrics"
+	requests "code.cloudfoundry.org/locket/metrics/helpers"
 	locketmodels "code.cloudfoundry.org/locket/models"
 	"code.cloudfoundry.org/rep"
 	"code.cloudfoundry.org/tlsconfig"
@@ -248,6 +249,16 @@ func main() {
 	logger.Info("report-interval", lager.Data{"value": bbsConfig.ReportInterval})
 	fileDescriptorTicker := clock.NewTicker(time.Duration(bbsConfig.ReportInterval))
 	requestStatsTicker := clock.NewTicker(time.Duration(bbsConfig.ReportInterval))
+	requestTypes := []string{
+		"DesiredLRPEndpoints",
+		"DesiredLRPLifecycleEndponts",
+		"ActualLRPSEndpoint",
+		"ActualLRPLifecycleEndpoints",
+		"StartActualLRPEndpoint",
+		"EvacuationEndpoints",
+		"TaskEndpoints",
+	}
+	requestMetrics := requests.NewRequestMetricsNotifier(logger, clock, metronClient, time.Duration(bbsConfig.ReportInterval), requestTypes)
 	locksHeldTicker := clock.NewTicker(time.Duration(bbsConfig.ReportInterval))
 
 	fileDescriptorPath := fmt.Sprintf("/proc/%d/fd", os.Getpid())
@@ -276,6 +287,7 @@ func main() {
 		taskStatMetronNotifier,
 		migrationsDone,
 		exitChan,
+		requestMetrics,
 	)
 
 	bbsElectionMetronNotifier := metrics.NewBBSElectionMetronNotifier(logger, metronClient)
@@ -359,6 +371,7 @@ func main() {
 		{Name: "lrp-stat-metron-notifier", Runner: lrpStatMetronNotifier},
 		{Name: "task-stat-metron-notifier", Runner: taskStatMetronNotifier},
 		{Name: "db-stat-metron-notifier", Runner: dbStatMetronNotifier},
+		{Name: "request-metrics-notifier", Runner: requestMetrics},
 	}
 
 	if bbsConfig.DebugAddress != "" {

handlers/actual_lrp_handlers.go

@@ -2,21 +2,27 @@ package handlers
 
 import (
 	"net/http"
+	"time"
 
 	"code.cloudfoundry.org/bbs/db"
 	"code.cloudfoundry.org/bbs/models"
 	"code.cloudfoundry.org/lager/v3"
+	"code.cloudfoundry.org/locket/metrics/helpers"
 )
 
 type ActualLRPHandler struct {
-	db       db.ActualLRPDB
-	exitChan chan<- struct{}
+	db             db.ActualLRPDB
+	exitChan       chan<- struct{}
+	requestMetrics helpers.RequestMetrics
+	metricsGroup   string
 }
 
-func NewActualLRPHandler(db db.ActualLRPDB, exitChan chan<- struct{}) *ActualLRPHandler {
+func NewActualLRPHandler(db db.ActualLRPDB, exitChan chan<- struct{}, requestMetrics helpers.RequestMetrics) *ActualLRPHandler {
 	return &ActualLRPHandler{
-		db:       db,
-		exitChan: exitChan,
+		db:             db,
+		exitChan:       exitChan,
+		requestMetrics: requestMetrics,
+		metricsGroup:   "ActualLRPSEndpoint",
 	}
 }
 
@@ -29,6 +35,10 @@ func (h *ActualLRPHandler) ActualLRPs(logger lager.Logger, w http.ResponseWriter
 	request := &models.ActualLRPsRequest{}
 	response := &models.ActualLRPsResponse{}
 
+	start := time.Now()
+	startMetrics(h.requestMetrics, h.metricsGroup)
+	defer stopMetrics(h.requestMetrics, h.metricsGroup, start, &err)
+
 	err = parseRequest(logger, req, request)
 	if err == nil {
 		var index *int32

handlers/actual_lrp_handlers_test.go

@@ -5,12 +5,16 @@ import (
 	"net/http"
 	"net/http/httptest"
 	"strings"
+	"time"
 
 	"code.cloudfoundry.org/bbs/db/dbfakes"
 	"code.cloudfoundry.org/bbs/handlers"
 	"code.cloudfoundry.org/bbs/models"
+	"code.cloudfoundry.org/clock"
+	mfakes "code.cloudfoundry.org/diego-logging-client/testhelpers"
 	"code.cloudfoundry.org/lager/v3"
 	"code.cloudfoundry.org/lager/v3/lagertest"
+	"code.cloudfoundry.org/locket/metrics/helpers"
 	. "github.com/onsi/ginkgo/v2"
 	. "github.com/onsi/gomega"
 	"github.com/onsi/gomega/gbytes"
@@ -23,6 +27,8 @@ var _ = Describe("ActualLRP Handlers", func() {
 		responseRecorder *httptest.ResponseRecorder
 		handler          *handlers.ActualLRPHandler
 		exitCh           chan struct{}
+		requestMetrics   *helpers.RequestMetricsNotifier
+		fakeMetronClient *mfakes.FakeIngressClient
 
 		actualLRP1     models.ActualLRP
 		actualLRP2     models.ActualLRP
@@ -76,7 +82,17 @@ var _ = Describe("ActualLRP Handlers", func() {
 		exitCh = make(chan struct{}, 1)
 		requestIdHeader = "f256f938-9e14-4abd-974f-63c6138f1cca"
 		b3RequestIdHeader = fmt.Sprintf(`"trace-id":"%s"`, strings.Replace(requestIdHeader, "-", "", -1))
-		handler = handlers.NewActualLRPHandler(fakeActualLRPDB, exitCh)
+
+		clock := clock.NewClock()
+		requestMetrics = helpers.NewRequestMetricsNotifier(
+			logger,
+			clock,
+			fakeMetronClient,
+			1*time.Minute,
+			[]string{"ActualLRPSEndpoint"},
+		)
+
+		handler = handlers.NewActualLRPHandler(fakeActualLRPDB, exitCh, requestMetrics)
 	})
 
 	Describe("ActualLRPs", func() {

handlers/actual_lrp_lifecycle_handler.go

@@ -3,10 +3,12 @@ package handlers
 import (
 	"context"
 	"net/http"
+	"time"
 
 	"code.cloudfoundry.org/bbs/models"
 	"code.cloudfoundry.org/bbs/trace"
 	"code.cloudfoundry.org/lager/v3"
+	"code.cloudfoundry.org/locket/metrics/helpers"
 )
 
 //go:generate counterfeiter -generate
@@ -31,28 +33,40 @@ type ActualLRPLifecycleController interface {
 }
 
 type ActualLRPLifecycleHandler struct {
-	controller ActualLRPLifecycleController
-	exitChan   chan<- struct{}
+	controller        ActualLRPLifecycleController
+	exitChan          chan<- struct{}
+	requestMetrics    helpers.RequestMetrics
+	metricsGroup      string
+	metricsGroupStart string
 }
 
 func NewActualLRPLifecycleHandler(
 	controller ActualLRPLifecycleController,
 	exitChan chan<- struct{},
+	requestMetrics helpers.RequestMetrics,
 ) *ActualLRPLifecycleHandler {
 	return &ActualLRPLifecycleHandler{
-		controller: controller,
-		exitChan:   exitChan,
+		controller:        controller,
+		exitChan:          exitChan,
+		requestMetrics:    requestMetrics,
+		metricsGroup:      "ActualLRPLifecycleEndpoints",
+		metricsGroupStart: "StartActualLRPEndpoint",
 	}
 }
 
 func (h *ActualLRPLifecycleHandler) ClaimActualLRP(logger lager.Logger, w http.ResponseWriter, req *http.Request) {
 	var err error
 	logger = logger.Session("claim-actual-lrp").WithTraceInfo(req)
-	logger.Debug("starting")
-	defer logger.Debug("complete")
+	logger.Info("starting")
+	defer logger.Info("complete")
 
 	request := &models.ClaimActualLRPRequest{}
 	response := &models.ActualLRPLifecycleResponse{}
+
+	start := time.Now()
+	startMetrics(h.requestMetrics, h.metricsGroup)
+	defer stopMetrics(h.requestMetrics, h.metricsGroup, start, &err)
+
 	defer func() { exitIfUnrecoverable(logger, h.exitChan, response.Error) }()
 	defer writeResponse(w, response)
 
@@ -67,17 +81,22 @@ func (h *ActualLRPLifecycleHandler) ClaimActualLRP(logger lager.Logger, w http.R
 }
 
 func (h *ActualLRPLifecycleHandler) StartActualLRP(logger lager.Logger, w http.ResponseWriter, req *http.Request) {
+	var err error
 	logger = logger.Session("start-actual-lrp").WithTraceInfo(req)
 	logger.Debug("starting")
 	defer logger.Debug("complete")
 
 	request := &models.StartActualLRPRequest{}
 	response := &models.ActualLRPLifecycleResponse{}
 
+	start := time.Now()
+	startMetrics(h.requestMetrics, h.metricsGroupStart)
+	defer stopMetrics(h.requestMetrics, h.metricsGroupStart, start, &err)
+
 	defer func() { exitIfUnrecoverable(logger, h.exitChan, response.Error) }()
 	defer writeResponse(w, response)
 
-	err := parseRequest(logger, req, request)
+	err = parseRequest(logger, req, request)
 	if err != nil {
 		response.Error = models.ConvertError(err)
 		return
@@ -119,16 +138,22 @@ func (h *ActualLRPLifecycleHandler) StartActualLRP_r0(logger lager.Logger, w htt
 }
 
 func (h *ActualLRPLifecycleHandler) CrashActualLRP(logger lager.Logger, w http.ResponseWriter, req *http.Request) {
+	var err error
 	logger = logger.Session("crash-actual-lrp").WithTraceInfo(req)
 	logger.Debug("starting")
 	defer logger.Debug("complete")
 
 	request := &models.CrashActualLRPRequest{}
 	response := &models.ActualLRPLifecycleResponse{}
+
+	start := time.Now()
+	startMetrics(h.requestMetrics, h.metricsGroup)
+	defer stopMetrics(h.requestMetrics, h.metricsGroup, start, &err)
+
 	defer func() { exitIfUnrecoverable(logger, h.exitChan, response.Error) }()
 	defer writeResponse(w, response)
 
-	err := parseRequest(logger, req, request)
+	err = parseRequest(logger, req, request)
 	if err != nil {
 		response.Error = models.ConvertError(err)
 		return
@@ -150,6 +175,10 @@ func (h *ActualLRPLifecycleHandler) FailActualLRP(logger lager.Logger, w http.Re
 	request := &models.FailActualLRPRequest{}
 	response := &models.ActualLRPLifecycleResponse{}
 
+	start := time.Now()
+	startMetrics(h.requestMetrics, h.metricsGroup)
+	defer stopMetrics(h.requestMetrics, h.metricsGroup, start, &err)
+
 	defer func() { exitIfUnrecoverable(logger, h.exitChan, response.Error) }()
 	defer writeResponse(w, response)
 
@@ -172,6 +201,10 @@ func (h *ActualLRPLifecycleHandler) RemoveActualLRP(logger lager.Logger, w http.
 	request := &models.RemoveActualLRPRequest{}
 	response := &models.ActualLRPLifecycleResponse{}
 
+	start := time.Now()
+	startMetrics(h.requestMetrics, h.metricsGroup)
+	defer stopMetrics(h.requestMetrics, h.metricsGroup, start, &err)
+
 	defer func() { exitIfUnrecoverable(logger, h.exitChan, response.Error) }()
 	defer writeResponse(w, response)
 
@@ -186,13 +219,17 @@ func (h *ActualLRPLifecycleHandler) RemoveActualLRP(logger lager.Logger, w http.
 }
 
 func (h *ActualLRPLifecycleHandler) RetireActualLRP(logger lager.Logger, w http.ResponseWriter, req *http.Request) {
+	var err error
 	logger = logger.Session("retire-actual-lrp").WithTraceInfo(req)
 	logger.Debug("starting")
 	defer logger.Debug("complete")
 	request := &models.RetireActualLRPRequest{}
 	response := &models.ActualLRPLifecycleResponse{}
 
-	var err error
+	start := time.Now()
+	startMetrics(h.requestMetrics, h.metricsGroup)
+	defer stopMetrics(h.requestMetrics, h.metricsGroup, start, &err)
+
 	defer func() { exitIfUnrecoverable(logger, h.exitChan, response.Error) }()
 	defer writeResponse(w, response)
 

handlers/actual_lrp_lifecycle_handler_test.go

@@ -6,13 +6,17 @@ import (
 	"net/http"
 	"net/http/httptest"
 	"strings"
+	"time"
 
 	"code.cloudfoundry.org/bbs/handlers"
 	"code.cloudfoundry.org/bbs/handlers/fake_controllers"
 	"code.cloudfoundry.org/bbs/models"
 	"code.cloudfoundry.org/bbs/serviceclient/serviceclientfakes"
+	"code.cloudfoundry.org/clock"
+	mfakes "code.cloudfoundry.org/diego-logging-client/testhelpers"
 	"code.cloudfoundry.org/lager/v3"
 	"code.cloudfoundry.org/lager/v3/lagertest"
+	"code.cloudfoundry.org/locket/metrics/helpers"
 	"code.cloudfoundry.org/rep/repfakes"
 	. "github.com/onsi/ginkgo/v2"
 	. "github.com/onsi/gomega"
@@ -25,7 +29,9 @@ var _ = Describe("ActualLRP Lifecycle Handlers", func() {
 		responseRecorder *httptest.ResponseRecorder
 		handler          *handlers.ActualLRPLifecycleHandler
 		fakeController   *fake_controllers.FakeActualLRPLifecycleController
+		fakeMetronClient *mfakes.FakeIngressClient
 		exitCh           chan struct{}
+		requestMetrics   *helpers.RequestMetricsNotifier
 
 		requestIdHeader   string
 		b3RequestIdHeader string
@@ -44,7 +50,17 @@ var _ = Describe("ActualLRP Lifecycle Handlers", func() {
 		requestIdHeader = "b67c32c0-1666-49dc-97c1-274332e6b706"
 		b3RequestIdHeader = fmt.Sprintf(`"trace-id":"%s"`, strings.Replace(requestIdHeader, "-", "", -1))
 		fakeController = &fake_controllers.FakeActualLRPLifecycleController{}
-		handler = handlers.NewActualLRPLifecycleHandler(fakeController, exitCh)
+
+		clock := clock.NewClock()
+		requestMetrics = helpers.NewRequestMetricsNotifier(
+			logger,
+			clock,
+			fakeMetronClient,
+			1*time.Minute,
+			[]string{"ActualLRPLifecycleEndpoints", "StartActualLRPEndpoint"},
+		)
+
+		handler = handlers.NewActualLRPLifecycleHandler(fakeController, exitCh, requestMetrics)
 	})
 
 	Describe("ClaimActualLRP", func() {

handlers/context_test.go

@@ -20,6 +20,7 @@ import (
 	"code.cloudfoundry.org/clock/fakeclock"
 	"code.cloudfoundry.org/diego-logging-client/testhelpers"
 	"code.cloudfoundry.org/lager/v3/lagertest"
+	requests "code.cloudfoundry.org/locket/metrics/helpers"
 	"github.com/tedsuo/ifrit"
 	ginkgomon "github.com/tedsuo/ifrit/ginkgomon_v2"
 
@@ -35,6 +36,7 @@ var _ = Describe("Context", func() {
 		sqlConn          *sql.DB
 		sqlProcess       ifrit.Process
 		migrationProcess ifrit.Process
+		requestMetrics   requests.RequestMetrics
 	)
 
 	BeforeEach(func() {
@@ -92,7 +94,7 @@ var _ = Describe("Context", func() {
 		Eventually(migrationsDone).Should(BeClosed())
 
 		exitCh := make(chan struct{}, 1)
-		handler = handlers.NewActualLRPHandler(sqlDB, exitCh)
+		handler = handlers.NewActualLRPHandler(sqlDB, exitCh, requestMetrics)
 	})
 
 	AfterEach(func() {