From 94cc35467aec9ea6d1abb4943532af0c3a92f6ca Mon Sep 17 00:00:00 2001 From: Scott Kay Date: Mon, 27 Jan 2020 14:03:34 -0500 Subject: [PATCH] Enhance Message For Cache Errors (#1175) --- prebid_cache_client/client.go | 34 ++++++------- prebid_cache_client/client_test.go | 80 ++++++++++++++++++++++-------- 2 files changed, 74 insertions(+), 40 deletions(-) diff --git a/prebid_cache_client/client.go b/prebid_cache_client/client.go index 6da69f68243..58e2734ed25 100644 --- a/prebid_cache_client/client.go +++ b/prebid_cache_client/client.go @@ -4,6 +4,7 @@ import ( "bytes" "context" "encoding/json" + "errors" "fmt" "io/ioutil" "net/http" @@ -92,15 +93,13 @@ func (c *clientImpl) PutJson(ctx context.Context, values []Cacheable) (uuids []s postBody, err := encodeValues(values) if err != nil { - glog.Errorf("Error creating JSON for prebid cache: %v", err) - errs = append(errs, fmt.Errorf("Error creating JSON for prebid cache: %v", err)) + logError(&errs, "Error creating JSON for prebid cache: %v", err) return uuidsToReturn, errs } httpReq, err := http.NewRequest("POST", c.putUrl, bytes.NewReader(postBody)) if err != nil { - glog.Errorf("Error creating POST request to prebid cache: %v", err) - errs = append(errs, fmt.Errorf("Error creating POST request to prebid cache: %v", err)) + logError(&errs, "Error creating POST request to prebid cache: %v", err) return uuidsToReturn, errs } @@ -112,9 +111,7 @@ func (c *clientImpl) PutJson(ctx context.Context, values []Cacheable) (uuids []s elapsedTime := time.Since(startTime) if err != nil { c.metrics.RecordPrebidCacheRequestTime(false, elapsedTime) - friendlyErr := fmt.Errorf("Error sending the request to Prebid Cache: %v; Duration=%v", err, elapsedTime) - glog.Error(friendlyErr) - errs = append(errs, friendlyErr) + logError(&errs, "Error sending the request to Prebid Cache: %v; Duration=%v, Items=%v, Payload Size=%v", err, elapsedTime, len(values), len(postBody)) return uuidsToReturn, errs } defer anResp.Body.Close() @@ -122,23 +119,19 @@ func (c *clientImpl) PutJson(ctx context.Context, values []Cacheable) (uuids []s responseBody, err := ioutil.ReadAll(anResp.Body) if anResp.StatusCode != 200 { - glog.Errorf("Prebid Cache call to %s returned %d: %s", putURL, anResp.StatusCode, responseBody) - errs = append(errs, fmt.Errorf("Prebid Cache call to %s returned %d: %s", putURL, anResp.StatusCode, responseBody)) + logError(&errs, "Prebid Cache call to %s returned %d: %s", putURL, anResp.StatusCode, responseBody) return uuidsToReturn, errs } currentIndex := 0 processResponse := func(uuidObj []byte, _ jsonparser.ValueType, _ int, err error) { if uuid, valueType, _, err := jsonparser.Get(uuidObj, "uuid"); err != nil { - glog.Errorf("Prebid Cache returned a bad value at index %d. Error was: %v. Response body was: %s", currentIndex, err, string(responseBody)) - errs = append(errs, fmt.Errorf("Prebid Cache returned a bad value at index %d. Error was: %v. Response body was: %s", currentIndex, err, string(responseBody))) + logError(&errs, "Prebid Cache returned a bad value at index %d. Error was: %v. Response body was: %s", currentIndex, err, string(responseBody)) } else if valueType != jsonparser.String { - glog.Errorf("Prebid Cache returned a %v at index %d in: %v", valueType, currentIndex, string(responseBody)) - errs = append(errs, fmt.Errorf("Prebid Cache returned a %v at index %d in: %v", valueType, currentIndex, string(responseBody))) + logError(&errs, "Prebid Cache returned a %v at index %d in: %v", valueType, currentIndex, string(responseBody)) } else { if uuidsToReturn[currentIndex], err = jsonparser.ParseString(uuid); err != nil { - glog.Errorf("Prebid Cache response index %d could not be parsed as string: %v", currentIndex, err) - errs = append(errs, fmt.Errorf("Prebid Cache response index %d could not be parsed as string: %v", currentIndex, err)) + logError(&errs, "Prebid Cache response index %d could not be parsed as string: %v", currentIndex, err) uuidsToReturn[currentIndex] = "" } } @@ -146,17 +139,20 @@ func (c *clientImpl) PutJson(ctx context.Context, values []Cacheable) (uuids []s } if _, err := jsonparser.ArrayEach(responseBody, processResponse, "responses"); err != nil { - glog.Errorf("Error interpreting Prebid Cache response: %v\nResponse was: %s", err, string(responseBody)) - errs = append(errs, fmt.Errorf("Error interpreting Prebid Cache response: %v\nResponse was: %s", err, string(responseBody))) + logError(&errs, "Error interpreting Prebid Cache response: %v\nResponse was: %s", err, string(responseBody)) return uuidsToReturn, errs } return uuidsToReturn, errs } +func logError(errs *[]error, format string, a ...interface{}) { + msg := fmt.Sprintf(format, a...) + glog.Error(msg) + *errs = append(*errs, errors.New(msg)) +} + func encodeValues(values []Cacheable) ([]byte, error) { - // This function assumes that m is non-nil and has at least one element. - // clientImp.PutBids should respect this. var buf bytes.Buffer buf.WriteString(`{"puts":[`) for i := 0; i < len(values); i++ { diff --git a/prebid_cache_client/client_test.go b/prebid_cache_client/client_test.go index d3b5ee4bfaf..1b5b4e38967 100644 --- a/prebid_cache_client/client_test.go +++ b/prebid_cache_client/client_test.go @@ -4,6 +4,7 @@ import ( "bytes" "context" "encoding/json" + "fmt" "net/http" "net/http/httptest" "strconv" @@ -17,7 +18,6 @@ import ( "github.com/stretchr/testify/mock" ) -// Prevents #197 func TestEmptyPut(t *testing.T) { handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { t.Errorf("The server should not be called.") @@ -72,32 +72,70 @@ func TestBadResponse(t *testing.T) { } func TestCancelledContext(t *testing.T) { - handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + testCases := []struct { + description string + cacheable []Cacheable + expectedItems int + expectedPayloadSize int + }{ + { + description: "1 Item", + cacheable: []Cacheable{ + { + Type: TypeJSON, + Data: json.RawMessage("true"), + }, + }, + expectedItems: 1, + expectedPayloadSize: 39, + }, + { + description: "2 Items", + cacheable: []Cacheable{ + { + Type: TypeJSON, + Data: json.RawMessage("true"), + }, + { + Type: TypeJSON, + Data: json.RawMessage("false"), + }, + }, + expectedItems: 2, + expectedPayloadSize: 69, + }, + } + + // Initialize Stub Server + stubHandler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(200) }) - server := httptest.NewServer(handler) - defer server.Close() + stubServer := httptest.NewServer(stubHandler) + defer stubServer.Close() - metricsMock := &pbsmetrics.MetricsEngineMock{} - metricsMock.On("RecordPrebidCacheRequestTime", false, mock.Anything).Once() + // Run Tests + for _, testCase := range testCases { + metricsMock := &pbsmetrics.MetricsEngineMock{} + metricsMock.On("RecordPrebidCacheRequestTime", false, mock.Anything).Once() - client := &clientImpl{ - httpClient: server.Client(), - putUrl: server.URL, - metrics: metricsMock, - } + client := &clientImpl{ + httpClient: stubServer.Client(), + putUrl: stubServer.URL, + metrics: metricsMock, + } - ctx, cancel := context.WithCancel(context.Background()) - cancel() - ids, _ := client.PutJson(ctx, []Cacheable{{ - Type: TypeJSON, - Data: json.RawMessage("true"), - }, - }) - assertIntEqual(t, len(ids), 1) - assertStringEqual(t, ids[0], "") + ctx, cancel := context.WithCancel(context.Background()) + cancel() + ids, errs := client.PutJson(ctx, testCase.cacheable) - metricsMock.AssertExpectations(t) + expectedErrorMessage := fmt.Sprintf("Items=%v, Payload Size=%v", testCase.expectedItems, testCase.expectedPayloadSize) + + assert.Equal(t, testCase.expectedItems, len(ids), testCase.description+":ids") + assert.Len(t, errs, 1) + assert.Contains(t, errs[0].Error(), "Error sending the request to Prebid Cache: context canceled", testCase.description+":error") + assert.Contains(t, errs[0].Error(), expectedErrorMessage, testCase.description+":error_dimensions") + metricsMock.AssertExpectations(t) + } } func TestSuccessfulPut(t *testing.T) {