[FABC-785] Add metrics for server APIs

Added rate, error, and duration metrics for server
APIs

Change-Id: Ia7ec7860ac4b8b177d49f84e1290000b53a67813
Signed-off-by: Saad Karim <skarim@us.ibm.com>

Author: Saad Karim

lib/server.go

@@ -25,14 +25,17 @@ import (
 	"github.com/cloudflare/cfssl/log"
 	"github.com/cloudflare/cfssl/revoke"
 	"github.com/cloudflare/cfssl/signer"
+	"github.com/felixge/httpsnoop"
 	gmux "github.com/gorilla/mux"
 	"github.com/hyperledger/fabric-ca/lib/attr"
 	"github.com/hyperledger/fabric-ca/lib/caerrors"
 	calog "github.com/hyperledger/fabric-ca/lib/common/log"
 	"github.com/hyperledger/fabric-ca/lib/dbutil"
 	"github.com/hyperledger/fabric-ca/lib/metadata"
+	"github.com/hyperledger/fabric-ca/lib/server/metrics"
 	stls "github.com/hyperledger/fabric-ca/lib/tls"
 	"github.com/hyperledger/fabric-ca/util"
+	"github.com/hyperledger/fabric/common/metrics/disabled"
 	"github.com/pkg/errors"
 	"github.com/spf13/viper"
 )
@@ -53,6 +56,8 @@ type Server struct {
 	BlockingStart bool
 	// The server's configuration
 	Config *ServerConfig
+	// Metrics are the metrics that the server tracks
+	Metrics metrics.Metrics
 	// The server mux
 	mux *gmux.Router
 	// The current listener for this server
@@ -107,10 +112,17 @@ func (s *Server) init(renew bool) (err error) {
 	if err != nil {
 		return err
 	}
+	s.initMetrics()
 	// Successful initialization
 	return nil
 }
 
+func (s *Server) initMetrics() {
+	provider := disabled.Provider{} // This is temporary, will eventually be replaced by actual provider
+	s.Metrics.APICounter = provider.NewCounter(metrics.APICounterOpts)
+	s.Metrics.APIDuration = provider.NewHistogram(metrics.APIDurationOpts)
+}
+
 // Start the fabric-ca server
 func (s *Server) Start() (err error) {
 	log.Infof("Starting server in home directory: %s", s.HomeDir)
@@ -489,10 +501,31 @@ func (s *Server) registerHandler(se *serverEndpoint) {
 
 func (s *Server) middleware(next http.Handler) http.Handler {
 	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
-		next.ServeHTTP(w, r)
+		metrics := httpsnoop.CaptureMetrics(next, w, r)
+		apiName := s.getAPIName(r)
+		caName := s.getCAName()
+		s.recordMetrics(metrics.Duration, caName, apiName, strconv.Itoa(metrics.Code))
 	})
 }
 
+func (s *Server) getAPIName(r *http.Request) string {
+	var apiName string
+	var match gmux.RouteMatch
+	if s.mux.Match(r, &match) {
+		apiName = match.Route.GetName()
+	}
+	return apiName
+}
+
+func (s *Server) getCAName() string {
+	return s.CA.Config.CA.Name
+}
+
+func (s *Server) recordMetrics(duration time.Duration, caName, apiName, statusCode string) {
+	s.Metrics.APICounter.With("ca_name", caName, "api_name", apiName, "status_code", statusCode).Add(1)
+	s.Metrics.APIDuration.With("ca_name", caName, "api_name", apiName, "status_code", statusCode).Observe(duration.Seconds())
+}
+
 // Starting listening and serving
 func (s *Server) listenAndServe() (err error) {
 
@@ -611,6 +644,7 @@ func (s *Server) serve() error {
 		// in https://jira.hyperledger.org/browse/FAB-3100.
 		return nil
 	}
+
 	s.serveError = http.Serve(listener, s.mux)
 	log.Errorf("Server has stopped serving: %s", s.serveError)
 	s.closeListener()

lib/server/metrics/metrics.go

@@ -0,0 +1,39 @@
+/*
+Copyright IBM Corp. All Rights Reserved.
+
+SPDX-License-Identifier: Apache-2.0
+*/
+
+package metrics
+
+import "github.com/hyperledger/fabric/common/metrics"
+
+var (
+	// APICounterOpts define the counter opts for server APIs
+	APICounterOpts = metrics.CounterOpts{
+		Namespace:    "api_request",
+		Subsystem:    "",
+		Name:         "count",
+		Help:         "Number of requests made to an API",
+		LabelNames:   []string{"ca_name", "api_name", "status_code"},
+		StatsdFormat: "%{#fqname}.%{ca_name}.%{api_name}.%{status_code}",
+	}
+
+	// APIDurationOpts define the duration opts for server APIs
+	APIDurationOpts = metrics.HistogramOpts{
+		Namespace:    "api_request",
+		Subsystem:    "",
+		Name:         "duration",
+		Help:         "Time taken in seconds for the request to an API to be completed",
+		LabelNames:   []string{"ca_name", "api_name", "status_code"},
+		StatsdFormat: "%{#fqname}.%{ca_name}.%{api_name}.%{status_code}",
+	}
+)
+
+// Metrics are the metrics tracked by server
+type Metrics struct {
+	// APICounter keeps track of number of times an API endpoint is called
+	APICounter metrics.Counter
+	// APIDuration keeps track of time taken for request to complete for an API
+	APIDuration metrics.Histogram
+}

lib/server_whitebox_test.go

@@ -16,11 +16,17 @@ limitations under the License.
 package lib
 
 import (
+	"net/http"
+	"net/http/httptest"
 	"os"
 	"testing"
 
 	"github.com/cloudflare/cfssl/log"
+	"github.com/gorilla/mux"
+	"github.com/hyperledger/fabric-ca/lib/server/metrics"
 	"github.com/hyperledger/fabric-ca/util"
+	"github.com/hyperledger/fabric/common/metrics/metricsfakes"
+	. "github.com/onsi/gomega"
 	"github.com/stretchr/testify/assert"
 )
 
@@ -118,3 +124,49 @@ func TestServerLogLevel(t *testing.T) {
 	err = srv.Init(false)
 	assert.Error(t, err, "Should fail, can't specify a log level and set debug true at same time")
 }
+
+func TestServerMetrics(t *testing.T) {
+	gt := NewGomegaWithT(t)
+
+	se := &serverEndpoint{
+		Path: "/test",
+	}
+
+	router := mux.NewRouter()
+	router.Handle(se.Path, se).Name(se.Path)
+
+	fakeCounter := &metricsfakes.Counter{}
+	fakeCounter.WithReturns(fakeCounter)
+	fakeHist := &metricsfakes.Histogram{}
+	fakeHist.WithReturns(fakeHist)
+	server := &Server{
+		CA: CA{
+			Config: &CAConfig{
+				CA: CAInfo{
+					Name: "ca1",
+				},
+			},
+		},
+		Metrics: metrics.Metrics{
+			APICounter:  fakeCounter,
+			APIDuration: fakeHist,
+		},
+		mux: router,
+	}
+
+	server.mux.Use(server.middleware)
+	se.Server = server
+
+	req, err := http.NewRequest("GET", "/test", nil)
+	gt.Expect(err).NotTo(HaveOccurred())
+
+	rr := httptest.NewRecorder()
+	router.ServeHTTP(rr, req)
+	gt.Expect(fakeCounter.AddCallCount()).To(Equal(1))
+	gt.Expect(fakeCounter.WithArgsForCall(0)).NotTo(BeZero())
+	gt.Expect(fakeCounter.WithArgsForCall(0)).To(Equal([]string{"ca_name", "ca1", "api_name", "/test", "status_code", "405"}))
+
+	gt.Expect(fakeHist.ObserveCallCount()).To(Equal(1))
+	gt.Expect(fakeHist.WithArgsForCall(0)).NotTo(BeZero())
+	gt.Expect(fakeHist.WithArgsForCall(0)).To(Equal([]string{"ca_name", "ca1", "api_name", "/test", "status_code", "405"}))
+}

scripts/run_unit_tests

@@ -16,7 +16,7 @@ go get github.com/AlekSi/gocov-xml
 # Skipping /lib/common package as there is only one file that contains request/response structs used by both client and server. It needs to be removed from exclude package list
 # when code is added to this package
 # Skipping credential package as there is only one file that contains Credential interface definition. It needs to be removed from exclude package list when code is added to this package
-PKGS=`go list github.com/hyperledger/fabric-ca/... | grep -Ev '/vendor/|/api|/dbutil|/ldap|/mocks|/test/fabric-ca-load-tester|/integration|/fabric-ca-client$|/credential$|/lib/common$'`
+PKGS=`go list github.com/hyperledger/fabric-ca/... | grep -Ev '/vendor/|/api|/dbutil|/ldap|/mocks|/test/fabric-ca-load-tester|/integration|/fabric-ca-client$|/credential$|/lib/common$|/metrics'`
 
 gocov test -timeout 15m $PKGS | gocov-xml > coverage.xml