Added AdsCert metrics (prebid#2351)

exchange/bidder.go

@@ -178,13 +178,16 @@ func (bidder *bidderAdapter) requestBid(ctx context.Context, bidderRequest Bidde
 				reqData[i].Headers.Add("Sec-GPC", reqInfo.GlobalPrivacyControlHeader)
 			}
 			if bidRequestOptions.addCallSignHeader {
+				startSignRequestTime := time.Now()
 				signatureMessage, err := adsCertSigner.Sign(reqData[i].Uri, reqData[i].Body)
+				bidder.me.RecordAdsCertSignTime(time.Since(startSignRequestTime))
 				if err != nil {
-					//add metrics here
+					bidder.me.RecordAdsCertReq(false)
 					errs = append(errs, &errortypes.Warning{Message: fmt.Sprintf("AdsCert signer is enabled but cannot sign the request: %s", err.Error())})
 				}
 				if err == nil && len(signatureMessage) > 0 {
 					reqData[i].Headers.Add(adscert.SignHeader, signatureMessage)
+					bidder.me.RecordAdsCertReq(true)
 				}
 			}
 

metrics/config/metrics.go

@@ -309,6 +309,18 @@ func (me *MultiMetricsEngine) RecordStoredResponse(pubId string) {
 	}
 }
 
+func (me *MultiMetricsEngine) RecordAdsCertReq(success bool) {
+	for _, thisME := range *me {
+		thisME.RecordAdsCertReq(success)
+	}
+}
+
+func (me *MultiMetricsEngine) RecordAdsCertSignTime(adsCertSignTime time.Duration) {
+	for _, thisME := range *me {
+		thisME.RecordAdsCertSignTime(adsCertSignTime)
+	}
+}
+
 // NilMetricsEngine implements the MetricsEngine interface where no metrics are actually captured. This is
 // used if no metric backend is configured and also for tests.
 type NilMetricsEngine struct{}
@@ -445,3 +457,11 @@ func (me *NilMetricsEngine) RecordDebugRequest(debugEnabled bool, pubId string)
 
 func (me *NilMetricsEngine) RecordStoredResponse(pubId string) {
 }
+
+func (me *NilMetricsEngine) RecordAdsCertReq(success bool) {
+
+}
+
+func (me *NilMetricsEngine) RecordAdsCertSignTime(adsCertSignTime time.Duration) {
+
+}

metrics/go_metrics.go

@@ -82,6 +82,11 @@ type Metrics struct {
 	exchanges []openrtb_ext.BidderName
 	// Will hold boolean values to help us disable metric collection if needed
 	MetricsDisabled config.DisabledMetrics
+
+	// AdsCert metrics
+	AdsCertRequestsSuccess metrics.Meter
+	AdsCertRequestsFailure metrics.Meter
+	adsCertSignTimer       metrics.Timer
 }
 
 // AdapterMetrics houses the metrics for a particular adapter
@@ -175,6 +180,10 @@ func NewBlankMetrics(registry metrics.Registry, exchanges []openrtb_ext.BidderNa
 		accountMetrics:  make(map[string]*accountMetrics),
 		MetricsDisabled: disabledMetrics,
 
+		AdsCertRequestsSuccess: blankMeter,
+		AdsCertRequestsFailure: blankMeter,
+		adsCertSignTimer:       blankTimer,
+
 		exchanges: exchanges,
 	}
 
@@ -309,6 +318,10 @@ func NewMetrics(registry metrics.Registry, exchanges []openrtb_ext.BidderName, d
 		newMetrics.PrivacyTCFRequestVersion[version] = metrics.GetOrRegisterMeter(fmt.Sprintf("privacy.request.tcf.%s", string(version)), registry)
 	}
 
+	newMetrics.AdsCertRequestsSuccess = metrics.GetOrRegisterMeter("ads_cert_requests.ok", registry)
+	newMetrics.AdsCertRequestsFailure = metrics.GetOrRegisterMeter("ads_cert_requests.failed", registry)
+	newMetrics.adsCertSignTimer = metrics.GetOrRegisterTimer("ads_cert_sign_time", registry)
+
 	return newMetrics
 }
 

metrics/go_metrics_test.go

@@ -74,6 +74,9 @@ func TestNewMetrics(t *testing.T) {
 	ensureContains(t, registry, "syncer.foo.request.type_not_supported", m.SyncerRequestsMeter["foo"][SyncerCookieSyncTypeNotSupported])
 	ensureContains(t, registry, "syncer.foo.set.ok", m.SyncerSetsMeter["foo"][SyncerSetUidOK])
 	ensureContains(t, registry, "syncer.foo.set.cleared", m.SyncerSetsMeter["foo"][SyncerSetUidCleared])
+
+	ensureContains(t, registry, "ads_cert_requests.ok", m.AdsCertRequestsSuccess)
+	ensureContains(t, registry, "ads_cert_requests.failed", m.AdsCertRequestsFailure)
 }
 
 func TestRecordBidType(t *testing.T) {
@@ -811,6 +814,70 @@ func TestStoredResponses(t *testing.T) {
 	}
 }
 
+func TestRecordAdsCertSignTime(t *testing.T) {
+	testCases := []struct {
+		description           string
+		inAdsCertSignDuration time.Duration
+		outExpDuration        time.Duration
+	}{
+		{
+			description:           "Five second AdsCertSign time",
+			inAdsCertSignDuration: time.Second * 5,
+			outExpDuration:        time.Second * 5,
+		},
+		{
+			description:           "Five millisecond AdsCertSign time",
+			inAdsCertSignDuration: time.Millisecond * 5,
+			outExpDuration:        time.Millisecond * 5,
+		},
+		{
+			description:           "Zero AdsCertSign time",
+			inAdsCertSignDuration: time.Duration(0),
+			outExpDuration:        time.Duration(0),
+		},
+	}
+	for _, test := range testCases {
+		registry := metrics.NewRegistry()
+		m := NewMetrics(registry, []openrtb_ext.BidderName{openrtb_ext.BidderAppnexus}, config.DisabledMetrics{}, nil)
+
+		m.RecordAdsCertSignTime(test.inAdsCertSignDuration)
+
+		assert.Equal(t, test.outExpDuration.Nanoseconds(), m.adsCertSignTimer.Sum(), test.description)
+	}
+}
+
+func TestRecordAdsCertReqMetric(t *testing.T) {
+	testCases := []struct {
+		description                  string
+		requestSuccess               bool
+		expectedSuccessRequestsCount int64
+		expectedFailedRequestsCount  int64
+	}{
+		{
+			description:                  "Record failed request, expected success request count is 0 and failed request count is 1",
+			requestSuccess:               false,
+			expectedSuccessRequestsCount: 0,
+			expectedFailedRequestsCount:  1,
+		},
+		{
+			description:                  "Record successful request, expected success request count is 1 and failed request count is 0",
+			requestSuccess:               true,
+			expectedSuccessRequestsCount: 1,
+			expectedFailedRequestsCount:  0,
+		},
+	}
+
+	for _, test := range testCases {
+		registry := metrics.NewRegistry()
+		m := NewMetrics(registry, []openrtb_ext.BidderName{openrtb_ext.BidderAppnexus}, config.DisabledMetrics{}, nil)
+
+		m.RecordAdsCertReq(test.requestSuccess)
+
+		assert.Equal(t, test.expectedSuccessRequestsCount, m.AdsCertRequestsSuccess.Count(), test.description)
+		assert.Equal(t, test.expectedFailedRequestsCount, m.AdsCertRequestsFailure.Count(), test.description)
+	}
+}
+
 func ensureContainsBidTypeMetrics(t *testing.T, registry metrics.Registry, prefix string, mdm map[openrtb_ext.BidType]*MarkupDeliveryMetrics) {
 	ensureContains(t, registry, prefix+".banner.adm_bids_received", mdm[openrtb_ext.BidTypeBanner].AdmMeter)
 	ensureContains(t, registry, prefix+".banner.nurl_bids_received", mdm[openrtb_ext.BidTypeBanner].NurlMeter)

metrics/metrics_mock.go

@@ -154,3 +154,11 @@ func (me *MetricsEngineMock) RecordDebugRequest(debugEnabled bool, pubId string)
 func (me *MetricsEngineMock) RecordStoredResponse(pubId string) {
 	me.Called(pubId)
 }
+
+func (me *MetricsEngineMock) RecordAdsCertReq(success bool) {
+	me.Called(success)
+}
+
+func (me *MetricsEngineMock) RecordAdsCertSignTime(adsCertSignTime time.Duration) {
+	me.Called(adsCertSignTime)
+}

metrics/prometheus/preload.go

@@ -145,6 +145,10 @@ func preloadLabelValues(m *Metrics, syncerKeys []string) {
 		hasBidsLabel: boolValues,
 	})
 
+	preloadLabelValuesForCounter(m.adsCertRequests, map[string][]string{
+		successLabel: boolValues,
+	})
+
 	if !m.metricsDisabled.AdapterConnectionMetrics {
 		preloadLabelValuesForCounter(m.adapterCreatedConnections, map[string][]string{
 			adapterLabel: adapterValues,

metrics/prometheus/prometheus.go

@@ -53,6 +53,8 @@ type Metrics struct {
 	storedResponses              prometheus.Counter
 	storedResponsesFetchTimer    *prometheus.HistogramVec
 	storedResponsesErrors        *prometheus.CounterVec
+	adsCertRequests              *prometheus.CounterVec
+	adsCertSignTimer             prometheus.Histogram
 
 	requestsDuplicateBidIDCounter prometheus.Counter // total request having duplicate bid.id for given bidder
 
@@ -444,6 +446,16 @@ func NewMetrics(cfg config.PrometheusMetrics, disabledMetrics config.DisabledMet
 		"Count of total requests to Prebid Server that have stored responses labled by account",
 		[]string{accountLabel})
 
+	metrics.adsCertSignTimer = newHistogram(cfg, reg,
+		"ads_cert_sign_time",
+		"Seconds to generate an AdsCert header",
+		standardTimeBuckets)
+
+	metrics.adsCertRequests = newCounter(cfg, reg,
+		"ads_cert_requests",
+		"Count of AdsCert request, and if they were successfully sent.",
+		[]string{successLabel})
+
 	metrics.Gatherer = reg
 
 	metricsPrefix := fmt.Sprintf("%s_%s_", cfg.Namespace, cfg.Subsystem)

metrics/prometheus/prometheus_test.go

@@ -1895,3 +1895,87 @@ func TestStoredResponsesMetric(t *testing.T) {
 		assertCounterValue(t, "", "stored responses", m.storedResponses, test.expectedStoredResponsesCount)
 	}
 }
+
+func TestRecordAdsCertReqMetric(t *testing.T) {
+	testCases := []struct {
+		description                  string
+		requestSuccess               bool
+		expectedSuccessRequestsCount float64
+		expectedFailedRequestsCount  float64
+	}{
+		{
+			description:                  "Record failed request, expected success request count is 0 and failed request count is 1",
+			requestSuccess:               false,
+			expectedSuccessRequestsCount: 0,
+			expectedFailedRequestsCount:  1,
+		},
+		{
+			description:                  "Record successful request, expected success request count is 1 and failed request count is 0",
+			requestSuccess:               true,
+			expectedSuccessRequestsCount: 1,
+			expectedFailedRequestsCount:  0,
+		},
+	}
+
+	for _, test := range testCases {
+		m := createMetricsForTesting()
+		m.RecordAdsCertReq(test.requestSuccess)
+		assertCounterVecValue(t, test.description, "successfully signed requests", m.adsCertRequests, test.expectedSuccessRequestsCount, prometheus.Labels{successLabel: requestSuccessful})
+		assertCounterVecValue(t, test.description, "unsuccessfully signed requests", m.adsCertRequests, test.expectedFailedRequestsCount, prometheus.Labels{successLabel: requestFailed})
+	}
+}
+
+func TestRecordAdsCertSignTime(t *testing.T) {
+	type testIn struct {
+		adsCertSignDuration time.Duration
+	}
+	type testOut struct {
+		expDuration float64
+		expCount    uint64
+	}
+	testCases := []struct {
+		description string
+		in          testIn
+		out         testOut
+	}{
+		{
+			description: "Five second AdsCert sign time",
+			in: testIn{
+				adsCertSignDuration: time.Second * 5,
+			},
+			out: testOut{
+				expDuration: 5,
+				expCount:    1,
+			},
+		},
+		{
+			description: "Five millisecond AdsCert sign time",
+			in: testIn{
+				adsCertSignDuration: time.Millisecond * 5,
+			},
+			out: testOut{
+				expDuration: 0.005,
+				expCount:    1,
+			},
+		},
+		{
+			description: "Zero AdsCert sign time",
+			in:          testIn{},
+			out: testOut{
+				expDuration: 0,
+				expCount:    1,
+			},
+		},
+	}
+	for i, test := range testCases {
+		pm := createMetricsForTesting()
+		pm.RecordAdsCertSignTime(test.in.adsCertSignDuration)
+
+		m := dto.Metric{}
+		pm.adsCertSignTimer.Write(&m)
+		histogram := *m.GetHistogram()
+
+		assert.Equal(t, test.out.expCount, histogram.GetSampleCount(), "[%d] Incorrect number of histogram entries. Desc: %s\n", i, test.description)
+		assert.Equal(t, test.out.expDuration, histogram.GetSampleSum(), "[%d] Incorrect number of histogram cumulative values. Desc: %s\n", i, test.description)
+	}
+}