Repository: honeycombio/refinery
Pull request #1010 (2024-02-23 23:47:22)

fix: Fix OTLP http responses
## Which problem is this PR solving?

Refinery was not returning the correct OTLP payload and not always using the correct `Content-Type` in the response.

- closes https://github.com/honeycombio/refinery/issues/1008

## Short description of the changes

This PR attempts to fix the OTLP response while leaving other protocols unaffected.

- Creates a new error handler method for the OTLP endpoint
- Ensures a `ExportTraceServiceResponse` object is returned for success and a grpc `Status` object is used for failure.
- Changes the "bad API key" response code from 400 to 401.



MikeGoldsmith: I'm open to making things better instead of just moving stuff around 😄 

> Leave it better than you found it 🎉 
robbkidd: I'm working on a quick repro to manual test the fix.
robbkidd: I've got otel-cli -> collector 0.95.0 -> refinery.

With a refinery build off the main branch and an invalid API key, I see the expected error in the collector:

```
Exporting failed. Will retry the request after interval.        {"kind": "exporter", "data_type": "traces", "name": "otlphttp", "error": "error parsing json response: ReadObjectCB: expect { or n, but found \u0000, error found in #0 byte of ...||..., bigger context ...||...", "interval": "7.423832335s"}
```

With a refinery build off this PR branch and an invalid API key, I don't see any error in the collector when I expect refinery to have sent an error response. 😕 
TylerHelmuth: @robbkidd the error you posted is the error this PR solves.  It would happen with or without an invalid key. 

Are you saying with this PR's build you don't see any error message returned from the call? 
robbkidd: > Are you saying with this PR's build you don't see any error message returned from the call?

Correct. With the new build from this PR, I do see an error if I omit the x-honeycomb-team header entirely:

```
Exporting failed. Dropping data.        {"kind": "exporter", "data_type": "traces", "name": "otlphttp",
 "error": "not retryable error: Permanent error: error exporting items, request to http://refinery:8080/v1/traces responded with HTTP Status Code 401, Message=missing 'x-honeycomb-team' header, Details=[]", "dropped_items": 1}
```

But I see no error back in the collector when the x-honeycomb-team header is present and given a random key. That should return an Unauthorized error response and fail the collector's export attempt, right?
TylerHelmuth: @robbkidd I agree with you, I get the same result.

I also tested `x-honeycomb-team` present with an invalid key against `main` (using telemetrygen directly) and got no error.  
TylerHelmuth: @robbkidd ok after looking through Refinery this make sense.  Refinery is currently only looking for specific keys if `AcceptOnlyListedKeys` is set, otherwise it just checks that the header is set and has the proper content type. If all that validation passes (which includes an invalid key), Refinery still accepts the span and then, when it tries to use the key to push to Honeycomb, it will fail.

Changing this behavior seems out of scope for this PR.  @kentquirk is there history behind this behavior? Should refinery be validating API keys it gets in the request?
kentquirk: Refinery specifically doesn't validate API keys by default because that then makes rolling keys more difficult. We also have considered (and will again) features where Refinery would maintain its own list of keys and replace some or all of the incoming keys.

If we change anything here, it would be a breaking change, so please don't do that now. We will certainly think about it again but it's a bigger product-level decision.
robbkidd: @TylerHelmuth Ah! My memory is refreshed! No. Changing  that is out of scope. I'll test with a list of acceptable keys for an error direct from Refinery. 
robbkidd: And that worked:

```
Exporting failed. Dropping data.        {"kind": "exporter", "data_type": "traces", "name": "otlphttp",
 "error": "not retryable error: Permanent error: error exporting items, request to http://refinery:8080/v1/traces responded with HTTP Status Code 401, Message=api key  not found in list of authorized keys, Details=[]", "dropped_items": 1}
```

Patch:
diff --git a/route/errors.go b/route/errors.go
index c901f8b..ba3ed5f 100644
--- a/route/errors.go
+++ b/route/errors.go
@@ -2,6 +2,7 @@ package route
 
 import (
 	"fmt"
+	"io"
 	"net/http"
 	"runtime/debug"
 
@@ -73,3 +74,25 @@ func (r *Router) handlerReturnWithError(w http.ResponseWriter, he handlerError,
 
 	w.Write(jsonErrMsg)
 }
+
+func (r *Router) handleOTLPFailureResponse(w http.ResponseWriter, req *http.Request, otlpErr husky.OTLPError) {
+	r.Logger.Error().Logf(otlpErr.Error())
+
+	if otlpErr != husky.ErrInvalidContentType {
+		err := husky.WriteOtlpHttpFailureResponse(w, req, otlpErr)
+		if err != nil {
+			// If we made it here we had a problem writing an OTLP HTTP response
+			resp := fmt.Sprintf("failed to write otlp http response, %v", err.Error())
+			r.Logger.Error().Logf(resp)
+			w.Header().Set("Content-Type", "text/plain")
+			w.WriteHeader(http.StatusInternalServerError)
+			_, _ = io.WriteString(w, resp)
+		}
+	} else {
+		// Since we have an invalid content type for an OTLP HTTP response we choose to use to text/plain
+		w.Header().Set("Content-Type", "text/plain")
+		w.WriteHeader(otlpErr.HTTPStatusCode)
+		_, _ = io.WriteString(w, otlpErr.Message)
+	}
+
+}
diff --git a/route/otlp_trace.go b/route/otlp_trace.go
index dc07fdc..6f74300 100644
--- a/route/otlp_trace.go
+++ b/route/otlp_trace.go
@@ -16,29 +16,31 @@ func (r *Router) postOTLP(w http.ResponseWriter, req *http.Request) {
 	ri := huskyotlp.GetRequestInfoFromHttpHeaders(req.Header)
 
 	if !r.Config.IsAPIKeyValid(ri.ApiKey) {
-		err := fmt.Errorf("api key %s not found in list of authorized keys", ri.ApiKey)
-		r.handlerReturnWithError(w, ErrAuthNeeded, err)
+		r.handleOTLPFailureResponse(w, req, huskyotlp.OTLPError{Message: fmt.Sprintf("api key %s not found in list of authorized keys", ri.ApiKey), HTTPStatusCode: http.StatusUnauthorized})
 		return
 	}
 
 	if err := ri.ValidateTracesHeaders(); err != nil {
 		if errors.Is(err, huskyotlp.ErrInvalidContentType) {
-			r.handlerReturnWithError(w, ErrInvalidContentType, err)
+			r.handleOTLPFailureResponse(w, req, huskyotlp.ErrInvalidContentType)
 		} else {
-			r.handlerReturnWithError(w, ErrAuthNeeded, err)
+			r.handleOTLPFailureResponse(w, req, huskyotlp.OTLPError{Message: err.Error(), HTTPStatusCode: http.StatusUnauthorized})
 		}
 		return
 	}
 
 	result, err := huskyotlp.TranslateTraceRequestFromReader(req.Body, ri)
 	if err != nil {
-		r.handlerReturnWithError(w, ErrUpstreamFailed, err)
+		r.handleOTLPFailureResponse(w, req, huskyotlp.OTLPError{Message: err.Error(), HTTPStatusCode: http.StatusInternalServerError})
 		return
 	}
 
 	if err := processTraceRequest(req.Context(), r, result.Batches, ri.ApiKey); err != nil {
-		r.handlerReturnWithError(w, ErrUpstreamFailed, err)
+		r.handleOTLPFailureResponse(w, req, huskyotlp.OTLPError{Message: err.Error(), HTTPStatusCode: http.StatusInternalServerError})
+		return
 	}
+
+	_ = huskyotlp.WriteOtlpHttpTraceSuccessResponse(w, req)
 }
 
 type TraceServer struct {
diff --git a/route/route.go b/route/route.go
index b608445..58ca7c8 100644
--- a/route/route.go
+++ b/route/route.go
@@ -904,7 +904,6 @@ func (r *Router) Watch(req *grpc_health_v1.HealthCheckRequest, server grpc_healt
 func (r *Router) AddOTLPMuxxer(muxxer *mux.Router) {
 	// require an auth header for OTLP requests
 	otlpMuxxer := muxxer.PathPrefix("/v1/").Methods("POST").Subrouter()
-	otlpMuxxer.Use(r.apiKeyChecker)
 
 	// handle OTLP trace requests
 	otlpMuxxer.HandleFunc("/traces", r.postOTLP).Name("otlp")


Test patch:
diff --git a/app/app_test.go b/app/app_test.go
index 1ad2065..c6cd558 100644
--- a/app/app_test.go
+++ b/app/app_test.go
@@ -317,7 +317,7 @@ func TestAppIntegrationWithUnauthorizedKey(t *testing.T) {
 
 	resp, err := http.DefaultTransport.RoundTrip(req)
 	assert.NoError(t, err)
-	assert.Equal(t, 400, resp.StatusCode)
+	assert.Equal(t, 401, resp.StatusCode)
 	data, err := io.ReadAll(resp.Body)
 	resp.Body.Close()
 	assert.NoError(t, err)
diff --git a/route/otlp_trace_test.go b/route/otlp_trace_test.go
index efdc672..10c9f8e 100644
--- a/route/otlp_trace_test.go
+++ b/route/otlp_trace_test.go
@@ -317,7 +317,7 @@ func TestOTLPHandler(t *testing.T) {
 		w := httptest.NewRecorder()
 		router.postOTLP(w, request)
 		assert.Equal(t, w.Code, http.StatusOK)
-		assert.Equal(t, "", w.Body.String())
+		assert.Equal(t, "{}", w.Body.String())
 
 		assert.Equal(t, 2, len(mockTransmission.Events))
 		mockTransmission.Flush()
@@ -409,7 +409,7 @@ func TestOTLPHandler(t *testing.T) {
 
 		w := httptest.NewRecorder()
 		router.postOTLP(w, request)
-		assert.Equal(t, http.StatusBadRequest, w.Code)
+		assert.Equal(t, http.StatusUnauthorized, w.Code)
 		assert.Contains(t, w.Body.String(), "not found in list of authorized keys")
 
 		assert.Equal(t, 0, len(mockTransmission.Events))