Merge pull request #151 from blackducksoftware/hub-response-times

add metric for tracking hub response times

pkg/hub/fetcher.go

@@ -39,12 +39,16 @@ type Fetcher struct {
 }
 
 func (hf *Fetcher) Login() error {
+	start := time.Now()
 	err := hf.client.Login(hf.username, hf.password)
+	recordHubResponseTime("login", time.Now().Sub(start))
 	return err
 }
 
 func (hf *Fetcher) fetchHubVersion() error {
+	start := time.Now()
 	currentVersion, err := hf.client.CurrentVersion()
+	recordHubResponseTime("version", time.Now().Sub(start))
 	if err != nil {
 		log.Errorf("unable to get hub version: %s", err.Error())
 		return err
@@ -94,8 +98,9 @@ func (hf *Fetcher) HubVersion() string {
 // - a completed status
 func (hf *Fetcher) FetchScanFromImage(image ImageInterface) (*ImageScan, error) {
 	queryString := fmt.Sprintf("name:%s", image.HubProjectNameSearchString())
+	startGetProjects := time.Now()
 	projectList, err := hf.client.ListProjects(&hubapi.GetListOptions{Q: &queryString})
-
+	recordHubResponseTime("projects", time.Now().Sub(startGetProjects))
 	recordHubResponse("projects", err == nil)
 
 	if err != nil {
@@ -128,8 +133,9 @@ func (hf *Fetcher) fetchImageScanUsingProject(project hubapi.Project, image Imag
 	}
 	q := fmt.Sprintf("versionName:%s", image.HubProjectVersionNameSearchString())
 	options := hubapi.GetListOptions{Q: &q}
+	startGetVersions := time.Now()
 	versionList, err := client.ListProjectVersions(*link, &options)
-
+	recordHubResponseTime("projectVersions", time.Now().Sub(startGetVersions))
 	recordHubResponse("projectVersions", err == nil)
 
 	if err != nil {
@@ -163,7 +169,9 @@ func (hf *Fetcher) fetchImageScanUsingProject(project hubapi.Project, image Imag
 		return nil, err
 	}
 
+	startGetRiskProfile := time.Now()
 	riskProfile, err := client.GetProjectVersionRiskProfile(*riskProfileLink)
+	recordHubResponseTime("projectVersionRiskProfile", time.Now().Sub(startGetRiskProfile))
 	recordHubResponse("projectVersionRiskProfile", err == nil)
 	if err != nil {
 		log.Errorf("error fetching project version risk profile: %v", err)
@@ -175,7 +183,9 @@ func (hf *Fetcher) fetchImageScanUsingProject(project hubapi.Project, image Imag
 		log.Errorf("error getting policy status link: %v", err)
 		return nil, err
 	}
+	startGetPolicyStatus := time.Now()
 	policyStatus, err := client.GetProjectVersionPolicyStatus(*policyStatusLink)
+	recordHubResponseTime("projectVersionPolicyStatus", time.Now().Sub(startGetPolicyStatus))
 	recordHubResponse("projectVersionPolicyStatus", err == nil)
 	if err != nil {
 		log.Errorf("error fetching project version policy status: %v", err)
@@ -193,7 +203,9 @@ func (hf *Fetcher) fetchImageScanUsingProject(project hubapi.Project, image Imag
 		log.Errorf("error getting code locations link: %v", err)
 		return nil, err
 	}
+	startGetCodeLocations := time.Now()
 	codeLocationsList, err := client.ListCodeLocations(*codeLocationsLink)
+	recordHubResponseTime("codeLocations", time.Now().Sub(startGetCodeLocations))
 	recordHubResponse("codeLocations", err == nil)
 	if err != nil {
 		log.Errorf("error fetching code locations: %v", err)
@@ -225,7 +237,9 @@ func (hf *Fetcher) fetchImageScanUsingProject(project hubapi.Project, image Imag
 		log.Errorf("error getting scan summaries link: %v", err)
 		return nil, err
 	}
+	startGetScanSummaries := time.Now()
 	scanSummariesList, err := client.ListScanSummaries(*scanSummariesLink)
+	recordHubResponseTime("scanSummaries", time.Now().Sub(startGetScanSummaries))
 	recordHubResponse("scanSummaries", err == nil)
 	if err != nil {
 		log.Errorf("error fetching scan summaries: %v", err)

pkg/hub/metrics.go

@@ -23,12 +23,14 @@ package hub
 
 import (
 	"fmt"
+	"time"
 
 	"github.com/prometheus/client_golang/prometheus"
 )
 
 var hubResponse *prometheus.CounterVec
 var hubData *prometheus.CounterVec
+var hubResponseTime *prometheus.HistogramVec
 
 func recordHubResponse(name string, isSuccessful bool) {
 	isSuccessString := fmt.Sprintf("%t", isSuccessful)
@@ -40,6 +42,11 @@ func recordHubData(name string, isOkay bool) {
 	hubData.With(prometheus.Labels{"name": name, "okay": isOkayString}).Inc()
 }
 
+func recordHubResponseTime(name string, duration time.Duration) {
+	milliseconds := float64(duration / time.Millisecond)
+	hubResponseTime.With(prometheus.Labels{"name": name}).Observe(milliseconds)
+}
+
 func init() {
 	hubResponse = prometheus.NewCounterVec(prometheus.CounterOpts{
 		Namespace:   "perceptor",
@@ -58,4 +65,13 @@ func init() {
 		ConstLabels: map[string]string{},
 	}, []string{"name", "okay"})
 	prometheus.MustRegister(hubData)
+
+	hubResponseTime = prometheus.NewHistogramVec(prometheus.HistogramOpts{
+		Namespace: "perceptor",
+		Subsystem: "core",
+		Name:      "hub_response_time",
+		Help:      "tracks the response times of Hub requests in milliseconds",
+		Buckets:   prometheus.ExponentialBuckets(1, 2, 20),
+	}, []string{"name"})
+	prometheus.MustRegister(hubResponseTime)
 }

pkg/hub/metrics_test.go

@@ -23,13 +23,15 @@ package hub
 
 import (
 	"testing"
+	"time"
 
 	log "github.com/sirupsen/logrus"
 )
 
 func TestMetrics(t *testing.T) {
 	recordHubData("abc", true)
 	recordHubResponse("qrs", false)
+	recordHubResponseTime("abc", time.Now().Sub(time.Now()))
 
 	message := "finished test case"
 	t.Log(message)