Add Stripe client telemetry to request headers

stripe.go

@@ -67,6 +67,10 @@ var LogLevel = 2
 // be overridden if a backend is created with GetBackendWithConfig.
 var Logger Printfer
 
+// EnableTelemetry allows request metrics (request id and duration) to be sent
+// to Stripe in subsequent requests via the `X-Stripe-Client-Telemetry` header.
+var EnableTelemetry = false
+
 //
 // Public types
 //
@@ -140,6 +144,13 @@ type BackendConfig struct {
 	URL string
 }
 
+// RequestMetrics contains the payload sent in the `X-Stripe-Client-Telemetry`
+// header when stripe.EnableTelemetry = true.
+type RequestMetrics struct {
+	RequestID         string `json:"request_id"`
+	RequestDurationMS int    `json:"request_duration_ms"`
+}
+
 // BackendImplementation is the internal implementation for making HTTP calls
 // to Stripe.
 //
@@ -158,6 +169,7 @@ type BackendImplementation struct {
 	//
 	// See also SetNetworkRetriesSleep.
 	networkRetriesSleep bool
+	lastRequestMetrics  *RequestMetrics
 }
 
 // Call is the Backend.Call implementation for invoking Stripe APIs.
@@ -292,8 +304,15 @@ func (s *BackendImplementation) Do(req *http.Request, body *bytes.Buffer, v inte
 		s.Logger.Printf("Requesting %v %v%v\n", req.Method, req.URL.Host, req.URL.Path)
 	}
 
+	if EnableTelemetry && s.lastRequestMetrics != nil {
+		metricsJSON, _ := json.Marshal(s.lastRequestMetrics)
+		payload := fmt.Sprintf(`{"last_request_metrics":%s}`, metricsJSON)
+		req.Header.Set("X-Stripe-Client-Telemetry", payload)
+	}
+
 	var res *http.Response
 	var err error
+	var requestDurationMS int
 	for retry := 0; ; {
 		start := time.Now()
 
@@ -338,8 +357,14 @@ func (s *BackendImplementation) Do(req *http.Request, body *bytes.Buffer, v inte
 			}
 		}
 
+		// `requestStart` is used solely for client telemetry and, unlike `start`,
+		// does not account for the time spent building the request body.
+		requestStart := time.Now()
+
 		res, err = s.HTTPClient.Do(req)
 
+		requestDurationMS = int(time.Since(requestStart) / time.Millisecond)
+
 		if s.LogLevel > 2 {
 			s.Logger.Printf("Request completed in %v (retry: %v)\n",
 				time.Since(start), retry)
@@ -387,6 +412,16 @@ func (s *BackendImplementation) Do(req *http.Request, body *bytes.Buffer, v inte
 		return err
 	}
 
+	if EnableTelemetry {
+		reqID := res.Header.Get("Request-Id")
+		if len(reqID) > 0 {
+			s.lastRequestMetrics = &RequestMetrics{
+				RequestID:         reqID,
+				RequestDurationMS: requestDurationMS,
+			}
+		}
+	}
+
 	defer res.Body.Close()
 
 	resBody, err := ioutil.ReadAll(res.Body)
@@ -886,6 +921,7 @@ func newBackendImplementation(backendType SupportedBackend, config *BackendConfi
 		Type:                backendType,
 		URL:                 config.URL,
 		networkRetriesSleep: true,
+		lastRequestMetrics:  nil,
 	}
 }
 

stripe_test.go

@@ -4,6 +4,7 @@ import (
 	"bytes"
 	"context"
 	"encoding/json"
+	"fmt"
 	"net/http"
 	"net/http/httptest"
 	"regexp"
@@ -165,6 +166,141 @@ func TestDo_RetryOnTimeout(t *testing.T) {
 	assert.Equal(t, uint32(2), atomic.LoadUint32(&counter))
 }
 
+// Test that telemetry metrics are not sent by default
+func TestDo_TelemetryDisabled(t *testing.T) {
+	type testServerResponse struct {
+		Message string `json:"message"`
+	}
+
+	message := "Hello, client."
+	requestNum := 0
+
+	testServer := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		// none of the requests should include telemetry metrics
+		assert.Equal(t, r.Header.Get("X-Stripe-Client-Telemetry"), "")
+
+		response := testServerResponse{Message: message}
+
+		data, err := json.Marshal(response)
+		assert.NoError(t, err)
+
+		_, err = w.Write(data)
+		assert.NoError(t, err)
+
+		requestNum++
+	}))
+	defer testServer.Close()
+
+	backend := stripe.GetBackendWithConfig(
+		stripe.APIBackend,
+		&stripe.BackendConfig{
+			LogLevel:          3,
+			MaxNetworkRetries: 0,
+			URL:               testServer.URL,
+		},
+	).(*stripe.BackendImplementation)
+
+	for i := 0; i < 2; i++ {
+		request, err := backend.NewRequest(
+			http.MethodGet,
+			"/hello",
+			"sk_test_123",
+			"application/x-www-form-urlencoded",
+			nil,
+		)
+		assert.NoError(t, err)
+
+		var response testServerResponse
+		err = backend.Do(request, nil, &response)
+
+		assert.NoError(t, err)
+		assert.Equal(t, message, response.Message)
+	}
+
+	// We should have seen exactly two requests.
+	assert.Equal(t, 2, requestNum)
+}
+
+// Test that telemetry metrics are sent on subsequent requests when
+// stripe.EnableTelemetry = true.
+func TestDo_TelemetryEnabled(t *testing.T) {
+	stripe.EnableTelemetry = true
+	defer func() {
+		stripe.EnableTelemetry = false
+	}()
+
+	type testServerResponse struct {
+		Message string `json:"message"`
+	}
+
+	type clientTelemetry struct {
+		LastRequestMetrics stripe.RequestMetrics `json:"last_request_metrics"`
+	}
+
+	message := "Hello, client."
+	requestNum := 0
+
+	testServer := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		telemetryStr := r.Header.Get("X-Stripe-Client-Telemetry")
+		switch requestNum {
+		case 0:
+			// the first request should not receive any metrics
+			assert.Equal(t, telemetryStr, "")
+		case 1:
+			// the second request should include the metrics for the first request
+			assert.Contains(t, telemetryStr, `"request_id":"req_0"`)
+
+			// the telemetry should properly unmarshal into stripe.RequestMetrics
+			var telemetry clientTelemetry
+			err := json.Unmarshal([]byte(telemetryStr), &telemetry)
+			assert.NoError(t, err)
+		default:
+			assert.Fail(t, "Should not have reached request %v", requestNum)
+		}
+
+		w.Header().Set("Request-Id", fmt.Sprintf("req_%d", requestNum))
+		response := testServerResponse{Message: message}
+
+		data, err := json.Marshal(response)
+		assert.NoError(t, err)
+
+		_, err = w.Write(data)
+		assert.NoError(t, err)
+
+		requestNum++
+	}))
+	defer testServer.Close()
+
+	backend := stripe.GetBackendWithConfig(
+		stripe.APIBackend,
+		&stripe.BackendConfig{
+			LogLevel:          3,
+			MaxNetworkRetries: 0,
+			URL:               testServer.URL,
+		},
+	).(*stripe.BackendImplementation)
+
+	for i := 0; i < 2; i++ {
+		request, err := backend.NewRequest(
+			http.MethodGet,
+			"/hello",
+			"sk_test_123",
+			"application/x-www-form-urlencoded",
+			nil,
+		)
+		assert.NoError(t, err)
+
+		var response testServerResponse
+		err = backend.Do(request, nil, &response)
+
+		assert.NoError(t, err)
+		assert.Equal(t, message, response.Message)
+	}
+
+	// We should have seen exactly two requests.
+	assert.Equal(t, 2, requestNum)
+}
+
 func TestFormatURLPath(t *testing.T) {
 	assert.Equal(t, "/v1/resources/1/subresources/2",
 		stripe.FormatURLPath("/v1/resources/%s/subresources/%s", "1", "2"))