Repository: google/exposure-notifications-server
Pull request #1013 (2020-09-20 20:19:52)

Return warnings instead of error when symptom onset is too long ago
Follow-up from GH-1005

This fixes a bug in ENX on iOS which processes the 200 partial response success as an error.

**Release Note**

<!-- Enter your extended release note in the below block. If the PR requires
additional action from users switching to the new release, include the string
"action required". If no release note is required, write "NONE". -->

```release-note
Return warnings instead of error when symptom onset is too long ago
```

google-oss-robot: [APPROVALNOTIFIER] This PR is **APPROVED**

This pull-request has been approved by: *<a href="https://github.com/google/exposure-notifications-server/pull/1013#" title="Author self-approved">sethvargo</a>*

The full list of commands accepted by this bot can be found [here](https://go.k8s.io/bot-commands?repo=google%2Fexposure-notifications-server).

The pull request process is described [here](https://git.k8s.io/community/contributors/guide/owners.md#the-code-review-process)

<details >
Needs approval from an approver in each of these files:

- ~~[OWNERS](https://github.com/google/exposure-notifications-server/blob/main/OWNERS)~~ [sethvargo]

Approvers can indicate their approval by writing `/approve` in a comment
Approvers can cancel approval by writing `/approve cancel` in a comment
</details>
<!-- META={"approvers":[]} -->
sethvargo: /assign @mikehelmick 
/want-lgtm @mikehelmick 
google-oss-robot: [APPROVALNOTIFIER] This PR is **APPROVED**

This pull-request has been approved by: *<a href="https://github.com/google/exposure-notifications-server/pull/1013#pullrequestreview-492235353" title="Approved">mikehelmick</a>*, *<a href="https://github.com/google/exposure-notifications-server/pull/1013#" title="Author self-approved">sethvargo</a>*

The full list of commands accepted by this bot can be found [here](https://go.k8s.io/bot-commands?repo=google%2Fexposure-notifications-server).

The pull request process is described [here](https://git.k8s.io/community/contributors/guide/owners.md#the-code-review-process)

<details >
Needs approval from an approver in each of these files:

- ~~[OWNERS](https://github.com/google/exposure-notifications-server/blob/main/OWNERS)~~ [mikehelmick,sethvargo]

Approvers can indicate their approval by writing `/approve` in a comment
Approvers can cancel approval by writing `/approve cancel` in a comment
</details>
<!-- META={"approvers":[]} -->

Patch:
diff --git a/docs/getting-started/publishing-temporary-exposure-keys.md b/docs/getting-started/publishing-temporary-exposure-keys.md
index 8654a07..6a98254 100644
--- a/docs/getting-started/publishing-temporary-exposure-keys.md
+++ b/docs/getting-started/publishing-temporary-exposure-keys.md
@@ -72,6 +72,10 @@ The content of the revision token cannot be used to infer that a client ever upl
 what their diagnosis status is. It is recommended that clients fill this spot in memory
 with random data in advance of TEK publish.
 
+The publish response may also include a `warnings` field. These are not errors,
+but may indicate a client-side bug in key generation or processing. These
+warnings are primarily for app developers and not end-users.
+
 ## Chaff Requests
 
 It may be possible for a server operator or network observer to glean
diff --git a/internal/generate/handler.go b/internal/generate/handler.go
index c57a2e8..11cd7d6 100644
--- a/internal/generate/handler.go
+++ b/internal/generate/handler.go
@@ -151,7 +151,7 @@ func (h *generateHandler) generate(ctx context.Context, regions []string) error
 			SymptomOnsetInterval: uint32(publish.Keys[intervalIdx].IntervalNumber),
 		}
 
-		exposures, err := h.transformer.TransformPublish(ctx, publish, regions, &claims, batchTime)
+		exposures, _, err := h.transformer.TransformPublish(ctx, publish, regions, &claims, batchTime)
 		if err != nil {
 			return fmt.Errorf("failed to transform generated exposures: %w", err)
 		}
@@ -174,7 +174,7 @@ func (h *generateHandler) generate(ctx context.Context, regions []string) error
 			claims.ReportType = revisedReportType
 			batchTime = batchTime.Add(h.config.KeyRevisionDelay)
 
-			exposures, err := h.transformer.TransformPublish(ctx, publish, regions, &claims, batchTime)
+			exposures, _, err := h.transformer.TransformPublish(ctx, publish, regions, &claims, batchTime)
 			if err != nil {
 				return fmt.Errorf("failed to transform generated exposures: %w", err)
 			}
diff --git a/internal/publish/model/exposure_model.go b/internal/publish/model/exposure_model.go
index 2819c0c..833991f 100644
--- a/internal/publish/model/exposure_model.go
+++ b/internal/publish/model/exposure_model.go
@@ -412,7 +412,10 @@ func ReportTypeTransmissionRisk(reportType string, providedTR int) int {
 // * 0 exposure Keys in the requests
 // * > Transformer.maxExposureKeys in the request
 //
-func (t *Transformer) TransformPublish(ctx context.Context, inData *verifyapi.Publish, regions []string, claims *verification.VerifiedClaims, batchTime time.Time) ([]*Exposure, error) {
+// The return params are the list of exposures, a list of warnings, and any
+// errors that occur.
+//
+func (t *Transformer) TransformPublish(ctx context.Context, inData *verifyapi.Publish, regions []string, claims *verification.VerifiedClaims, batchTime time.Time) ([]*Exposure, []string, error) {
 	logger := logging.FromContext(ctx)
 	if t.debugReleaseSameDay {
 		logger.Errorf("DEBUG SERVER - Current day keys are not being embargoed.")
@@ -422,12 +425,12 @@ func (t *Transformer) TransformPublish(ctx context.Context, inData *verifyapi.Pu
 	if len(inData.Keys) == 0 {
 		msg := "no exposure keys in publish request"
 		logger.Debugf(msg)
-		return nil, fmt.Errorf(msg)
+		return nil, nil, fmt.Errorf(msg)
 	}
 	if len(inData.Keys) > t.maxExposureKeys {
 		msg := fmt.Sprintf("too many exposure keys in publish: %v, max of %v is allowed", len(inData.Keys), t.maxExposureKeys)
 		logger.Debugf(msg)
-		return nil, fmt.Errorf(msg)
+		return nil, nil, fmt.Errorf(msg)
 	}
 
 	onsetInterval := inData.SymptomOnsetInterval
@@ -459,11 +462,12 @@ func (t *Transformer) TransformPublish(ctx context.Context, inData *verifyapi.Pu
 		upcaseRegions[i] = strings.ToUpper(r)
 	}
 
+	var transformWarnings []string
 	var transformErrors *multierror.Error
 	for i, exposureKey := range inData.Keys {
 		exposure, err := TransformExposureKey(exposureKey, inData.HealthAuthorityID, upcaseRegions, &settings)
 		if err != nil {
-			logger.Debugf("individual key transform failed: %v", err)
+			logger.Debugw("individual key transform failed", "error", err)
 			transformErrors = multierror.Append(transformErrors, fmt.Errorf("key %d cannot be imported: %w", i, err))
 			continue
 		}
@@ -480,13 +484,21 @@ func (t *Transformer) TransformPublish(ctx context.Context, inData *verifyapi.Pu
 		// Set days since onset, either from the API or from the verified claims (see above).
 		if onsetInterval > 0 {
 			daysSince := DaysFromSymptomOnset(onsetInterval, exposure.IntervalNumber)
-			// Check if the magnitude of this value is too large. If it is too large, we won't want to set
-			// a days since symptom onset value ont he TEK itself, but we do want to warn the application devloper
-			// that this value (not TEK) was dropped.
-			// There are launched applications using this sever that rely on this behavior.
+			// Check if the magnitude of this value is too large. If it is too large,
+			// we won't want to set a days since symptom onset value on the TEK
+			// itself, but we do want to warn the application developer that this
+			// value (not TEK) was dropped.
+			//
+			// There are launched applications using this sever that rely on this
+			// behavior.
+			//
+			// Note that previously this returned an error, but this broke the iOS
+			// implementation since it is unable to handle partial success. As such,
+			// it was converted to a warning that's a separate field in the API
+			// response.
 			if abs := math.Abs(float64(daysSince)); abs > t.maxSymptomOnsetDays {
 				logger.Debugw("setting days since symptom onset to null on key due to symptom onset magnitude too high", "daysSince", daysSince)
-				transformErrors = multierror.Append(transformErrors, fmt.Errorf("key %d symptom onset is too large, %v > %v - saving without days since symptom onset", i, abs, t.maxSymptomOnsetDays))
+				transformWarnings = append(transformWarnings, fmt.Sprintf("key %d symptom onset is too large, %v > %v - saving without days since symptom onset", i, abs, t.maxSymptomOnsetDays))
 			} else {
 				// The value is within acceptable range, save it.
 				exposure.SetDaysSinceSymptomOnset(daysSince)
@@ -498,7 +510,7 @@ func (t *Transformer) TransformPublish(ctx context.Context, inData *verifyapi.Pu
 
 	if len(entities) == 0 {
 		// All keys in the batch are valid.
-		return nil, transformErrors.ErrorOrNil()
+		return nil, transformWarnings, transformErrors.ErrorOrNil()
 	}
 
 	// Validate the uploaded data meets configuration parameters.
@@ -534,7 +546,7 @@ func (t *Transformer) TransformPublish(ctx context.Context, inData *verifyapi.Pu
 		if ex.IntervalNumber < nextInterval {
 			msg := fmt.Sprintf("exposure keys have non aligned overlapping intervals. %v overlaps with previous key that is good from %v to %v.", ex.IntervalNumber, lastInterval, nextInterval)
 			logger.Debugf(msg)
-			return nil, fmt.Errorf(msg)
+			return nil, transformWarnings, fmt.Errorf(msg)
 		}
 		// OK, current key starts at or after the end of the previous one. Advance both variables.
 		lastInterval = ex.IntervalNumber
@@ -545,9 +557,9 @@ func (t *Transformer) TransformPublish(ctx context.Context, inData *verifyapi.Pu
 		if v > t.maxSameDayKeys {
 			msg := fmt.Sprintf("too many overlapping keys for start interval: %v want: <= %v, got: %v", k, t.maxSameDayKeys, v)
 			logger.Debugf(msg)
-			return nil, fmt.Errorf(msg)
+			return nil, transformWarnings, fmt.Errorf(msg)
 		}
 	}
 
-	return entities, transformErrors.ErrorOrNil()
+	return entities, transformWarnings, transformErrors.ErrorOrNil()
 }
diff --git a/internal/publish/publish.go b/internal/publish/publish.go
index f7edb80..b1d2f4e 100644
--- a/internal/publish/publish.go
+++ b/internal/publish/publish.go
@@ -319,7 +319,7 @@ func (h *PublishHandler) process(ctx context.Context, data *verifyapi.Publish, b
 	}
 
 	batchTime := time.Now()
-	exposures, transformError := h.transformer.TransformPublish(ctx, data, regions, verifiedClaims, batchTime)
+	exposures, transformWarnings, transformError := h.transformer.TransformPublish(ctx, data, regions, verifiedClaims, batchTime)
 	// Check for non-recoverable error. It is possible that individual keys are dropped, but if there
 	// are any valid ones, we will try and move forward.
 	// If at the end, there is a success, the transformError will be returned as supplemental information.
@@ -332,6 +332,7 @@ func (h *PublishHandler) process(ctx context.Context, data *verifyapi.Publish, b
 			pubResponse: &verifyapi.PublishResponse{
 				ErrorMessage: message,
 				Code:         verifyapi.ErrorBadRequest,
+				Warnings:     transformWarnings,
 			},
 			metrics: func() {
 				metricsMiddleWare.RecordTransformFail(ctx)
@@ -381,6 +382,7 @@ func (h *PublishHandler) process(ctx context.Context, data *verifyapi.Publish, b
 			pubResponse: &verifyapi.PublishResponse{
 				ErrorMessage: errorMessage,
 				Code:         errorCode,
+				Warnings:     transformWarnings,
 			},
 			metrics: func() {
 				metricsMiddleWare.RecordRevisionTokenIssue(ctx, metric)
@@ -418,6 +420,7 @@ func (h *PublishHandler) process(ctx context.Context, data *verifyapi.Publish, b
 	publishResponse := verifyapi.PublishResponse{
 		RevisionToken:     base64.StdEncoding.EncodeToString(newToken),
 		InsertedExposures: int(resp.Inserted),
+		Warnings:          transformWarnings,
 	}
 	// If there was a partial failure on transform, add that information back into the success response.
 	if transformError != nil {
diff --git a/internal/publish/publish_v1alpha1.go b/internal/publish/publish_v1alpha1.go
index 4958cf9..e3ac66a 100644
--- a/internal/publish/publish_v1alpha1.go
+++ b/internal/publish/publish_v1alpha1.go
@@ -100,6 +100,7 @@ func (h *PublishHandler) HandleV1Alpha1() http.Handler {
 				InsertedExposures: response.pubResponse.InsertedExposures,
 				Error:             response.pubResponse.ErrorMessage,
 				Padding:           response.pubResponse.Padding,
+				Warnings:          response.pubResponse.Warnings,
 			}
 
 			if response.metrics != nil {
diff --git a/pkg/api/v1/exposure_types.go b/pkg/api/v1/exposure_types.go
index 66cac19..2bd039e 100644
--- a/pkg/api/v1/exposure_types.go
+++ b/pkg/api/v1/exposure_types.go
@@ -125,12 +125,16 @@ type Publish struct {
 //
 // The Padding field may be populated with random data on both success and
 // error responses.
+//
+// The Warnings field may be populated with a list of warnings. These are not
+// errors, but may indicate the server mutated the response.
 type PublishResponse struct {
-	RevisionToken     string `json:"revisionToken,omitempty"`
-	InsertedExposures int    `json:"insertedExposures,omitempty"`
-	ErrorMessage      string `json:"error,omitempty"`
-	Code              string `json:"code,omitempty"`
-	Padding           string `json:"padding,omitempty"`
+	RevisionToken     string   `json:"revisionToken,omitempty"`
+	InsertedExposures int      `json:"insertedExposures,omitempty"`
+	ErrorMessage      string   `json:"error,omitempty"`
+	Code              string   `json:"code,omitempty"`
+	Padding           string   `json:"padding,omitempty"`
+	Warnings          []string `json:"warnings,omitempty"`
 }
 
 // ExposureKey is the 16 byte key, the start time of the key and the
diff --git a/pkg/api/v1alpha1/exposure_types.go b/pkg/api/v1alpha1/exposure_types.go
index f1cb8cd..86b52a6 100644
--- a/pkg/api/v1alpha1/exposure_types.go
+++ b/pkg/api/v1alpha1/exposure_types.go
@@ -83,19 +83,23 @@ type Publish struct {
 	DeviceVerificationPayload string `json:"deviceVerificationPayload"` // DEPRECATED
 }
 
-// PublishResponse is sent back to the client on a publish request.
-// If successful, the revisionToken indicates an opaque string that must be
-// passed back if the same devices wishes to publish TEKs again.
+// PublishResponse is sent back to the client on a publish request. If
+// successful, the revisionToken indicates an opaque string that must be passed
+// back if the same devices wishes to publish TEKs again.
 //
 // On error, the error field will contain the error details.
 //
-// The Padding field may be populated with random data on both success and
-// error responses.
+// The Padding field may be populated with random data on both success and error
+// responses.
+//
+// The Warnings field may be populated with a list of warnings. These are not
+// errors, but may indicate the server mutated the response.
 type PublishResponse struct {
-	RevisionToken     string `json:"revisionToken"`
-	InsertedExposures int    `json:"insertedExposures"`
-	Error             string `json:"error"`
-	Padding           string `json:"padding"`
+	RevisionToken     string   `json:"revisionToken"`
+	InsertedExposures int      `json:"insertedExposures"`
+	Error             string   `json:"error"`
+	Padding           string   `json:"padding"`
+	Warnings          []string `json:"warnings,omitempty"`
 }
 
 // ExposureKey is the 16 byte key, the start time of the key and the


Test patch:
diff --git a/internal/publish/model/exposure_model_test.go b/internal/publish/model/exposure_model_test.go
index cef0da3..73b86a8 100644
--- a/internal/publish/model/exposure_model_test.go
+++ b/internal/publish/model/exposure_model_test.go
@@ -19,6 +19,8 @@ import (
 	"crypto/rand"
 	"encoding/base64"
 	"fmt"
+	"reflect"
+	"sort"
 	"strings"
 	"testing"
 	"time"
@@ -121,7 +123,7 @@ func TestInvalidBase64(t *testing.T) {
 	regions := []string{"US"}
 	batchTime := time.Date(2020, 3, 1, 10, 43, 1, 0, time.UTC)
 
-	_, err = transformer.TransformPublish(ctx, source, regions, nil, batchTime)
+	_, _, err = transformer.TransformPublish(ctx, source, regions, nil, batchTime)
 	expErr := `key 0 cannot be imported: illegal base64 data at input byte 4`
 	if err == nil || !strings.Contains(err.Error(), expErr) {
 		t.Errorf("expected error '%v', got: %v", expErr, err)
@@ -312,7 +314,7 @@ func TestPublishValidation(t *testing.T) {
 				t.Fatalf("unepected error: %v", err)
 			}
 
-			_, err = tf.TransformPublish(ctx, c.p, []string{}, nil, captureStartTime)
+			_, _, err = tf.TransformPublish(ctx, c.p, []string{}, nil, captureStartTime)
 			if err == nil {
 				if c.m != "" {
 					t.Errorf("want error '%v', got nil", c.m)
@@ -392,7 +394,7 @@ func TestStillValidKey(t *testing.T) {
 			}
 
 			ctx := context.Background()
-			tf, err := transformer.TransformPublish(ctx, &tc.source, []string{}, nil, now)
+			tf, _, err := transformer.TransformPublish(ctx, &tc.source, []string{}, nil, now)
 			if err != nil {
 				t.Fatal(err)
 			}
@@ -460,6 +462,7 @@ func TestTransform(t *testing.T) {
 		Claims       *verification.VerifiedClaims
 		Want         []*Exposure
 		PartialError string
+		Warnings     []string
 	}{
 		{
 			Name: "basic_v1_publish",
@@ -775,7 +778,7 @@ func TestTransform(t *testing.T) {
 					HealthAuthorityID:     int64Ptr(27),
 				},
 			},
-			PartialError: "key 1 symptom onset is too large, 15 > 14 - saving without days since symptom onset",
+			Warnings: []string{"key 1 symptom onset is too large, 15 > 14 - saving without days since symptom onset"},
 		},
 	}
 
@@ -788,7 +791,7 @@ func TestTransform(t *testing.T) {
 
 	for _, tc := range cases {
 		t.Run(tc.Name, func(t *testing.T) {
-			got, err := transformer.TransformPublish(ctx, tc.Publish, tc.Regions, tc.Claims, batchTime)
+			got, warnings, err := transformer.TransformPublish(ctx, tc.Publish, tc.Regions, tc.Claims, batchTime)
 			if err != nil && tc.PartialError == "" {
 				t.Fatalf("TransformPublish returned unexpected error: %v", err)
 			} else if tc.PartialError != "" {
@@ -799,6 +802,15 @@ func TestTransform(t *testing.T) {
 				}
 			}
 
+			if exp := tc.Warnings; len(exp) > 0 {
+				sort.Strings(exp)
+				sort.Strings(warnings)
+
+				if !reflect.DeepEqual(exp, warnings) {
+					t.Errorf("expected %#v to be %#v", warnings, exp)
+				}
+			}
+
 			if diff := cmp.Diff(tc.Want, got, cmpopts.IgnoreUnexported(Exposure{})); diff != "" {
 				t.Errorf("TransformPublish mismatch (-want +got):\n%v", diff)
 			}
@@ -951,7 +963,7 @@ func TestTransformOverlapping(t *testing.T) {
 			if err != nil {
 				t.Fatalf("NewTransformer returned unexpected error: %v", err)
 			}
-			_, err = transformer.TransformPublish(ctx, &tc.source, tc.regions, nil, now)
+			_, _, err = transformer.TransformPublish(ctx, &tc.source, tc.regions, nil, now)
 			if err != nil && tc.error == "" {
 				t.Fatalf("unexpected error, want: nil, got: %v", err)
 			} else if err != nil && !strings.Contains(err.Error(), tc.error) {