From e97e0a4c22e9caab8deb51c0b86be2345ee79a1c Mon Sep 17 00:00:00 2001 From: Mike Goldsmth Date: Tue, 1 Oct 2024 15:56:31 +0100 Subject: [PATCH 1/5] feat: Record incoming UserAgent in event metadata --- app/app_test.go | 15 +++++++++++ route/otlp_logs.go | 4 +-- route/otlp_logs_test.go | 57 ++++++++++++++++++++++++++++++++++++++++ route/otlp_trace.go | 4 +-- route/otlp_trace_test.go | 51 +++++++++++++++++++++++++++++++++++ route/route.go | 12 ++++++++- 6 files changed, 138 insertions(+), 5 deletions(-) diff --git a/app/app_test.go b/app/app_test.go index 3b3904cc4c..a078196dec 100644 --- a/app/app_test.go +++ b/app/app_test.go @@ -10,6 +10,7 @@ import ( "net/http" "net/http/httptest" "os" + "runtime" "strconv" "strings" "sync" @@ -27,6 +28,7 @@ import ( "github.com/honeycombio/libhoney-go" "github.com/honeycombio/libhoney-go/transmission" + "github.com/honeycombio/libhoney-go/version" "github.com/honeycombio/refinery/collect" "github.com/honeycombio/refinery/config" "github.com/honeycombio/refinery/internal/health" @@ -392,6 +394,7 @@ func TestPeerRouting(t *testing.T) { "field10": float64(10), "long": "this is a test of the emergency broadcast system", "meta.refinery.original_sample_rate": uint(2), + "meta.refinery.incoming_user_agent": getLibhoneyUserAgent(), "foo": "bar", }, Metadata: map[string]any{ @@ -517,6 +520,7 @@ func TestEventsEndpoint(t *testing.T) { "trace.trace_id": "1", "foo": "bar", "meta.refinery.original_sample_rate": uint(10), + "meta.refinery.incoming_user_agent": getLibhoneyUserAgent(), }, Metadata: map[string]any{ "api_host": "http://api.honeycomb.io", @@ -566,6 +570,7 @@ func TestEventsEndpoint(t *testing.T) { "trace.trace_id": "1", "foo": "bar", "meta.refinery.original_sample_rate": uint(10), + "meta.refinery.incoming_user_agent": getLibhoneyUserAgent(), }, Metadata: map[string]any{ "api_host": "http://api.honeycomb.io", @@ -639,6 +644,7 @@ func TestEventsEndpointWithNonLegacyKey(t *testing.T) { "trace.trace_id": traceID, "foo": "bar", "meta.refinery.original_sample_rate": uint(10), + "meta.refinery.incoming_user_agent": getLibhoneyUserAgent(), }, Metadata: map[string]any{ "api_host": "http://api.honeycomb.io", @@ -688,6 +694,7 @@ func TestEventsEndpointWithNonLegacyKey(t *testing.T) { "trace.trace_id": traceID, "foo": "bar", "meta.refinery.original_sample_rate": uint(10), + "meta.refinery.incoming_user_agent": getLibhoneyUserAgent(), }, Metadata: map[string]any{ "api_host": "http://api.honeycomb.io", @@ -908,3 +915,11 @@ func BenchmarkDistributedTraces(b *testing.B) { sender.waitForCount(b, b.N) }) } + +// ideally we should get this from libhoney, but we don't have a way to get it yet +// this can be removed if libhoney does provide it +func getLibhoneyUserAgent() string { + baseUserAgent := fmt.Sprintf("libhoney-go/%s", version.Version) + runtimeInfo := fmt.Sprintf("%s (%s/%s)", strings.Replace(runtime.Version(), "go", "go/", 1), runtime.GOOS, runtime.GOARCH) + return fmt.Sprintf("%s %s", baseUserAgent, runtimeInfo) +} diff --git a/route/otlp_logs.go b/route/otlp_logs.go index 371e1f1af9..3b2c2b2889 100644 --- a/route/otlp_logs.go +++ b/route/otlp_logs.go @@ -38,7 +38,7 @@ func (r *Router) postOTLPLogs(w http.ResponseWriter, req *http.Request) { return } - if err := r.processOTLPRequest(req.Context(), result.Batches, keyToUse); err != nil { + if err := r.processOTLPRequest(req.Context(), result.Batches, keyToUse, ri.UserAgent); err != nil { r.handleOTLPFailureResponse(w, req, huskyotlp.OTLPError{Message: err.Error(), HTTPStatusCode: http.StatusInternalServerError}) return } @@ -74,7 +74,7 @@ func (l *LogsServer) Export(ctx context.Context, req *collectorlogs.ExportLogsSe return nil, huskyotlp.AsGRPCError(err) } - if err := l.router.processOTLPRequest(ctx, result.Batches, keyToUse); err != nil { + if err := l.router.processOTLPRequest(ctx, result.Batches, keyToUse, ri.UserAgent); err != nil { return nil, huskyotlp.AsGRPCError(err) } diff --git a/route/otlp_logs_test.go b/route/otlp_logs_test.go index 5ba74ab758..0a0789a374 100644 --- a/route/otlp_logs_test.go +++ b/route/otlp_logs_test.go @@ -375,6 +375,63 @@ func TestLogsOTLPHandler(t *testing.T) { assert.Equal(t, 0, len(router.Collector.(*collect.MockCollector).Spans)) mockCollector.Flush() }) + + t.Run("logs record incoming user agent - gRPC", func(t *testing.T) { + md := metadata.New(map[string]string{"x-honeycomb-team": legacyAPIKey, "x-honeycomb-dataset": "ds", "user-agent": "my-user-agent"}) + ctx := metadata.NewIncomingContext(context.Background(), md) + + req := &collectorlogs.ExportLogsServiceRequest{ + ResourceLogs: []*logs.ResourceLogs{{ + ScopeLogs: []*logs.ScopeLogs{{ + LogRecords: createLogsRecords(), + }}, + }}, + } + _, err := logsServer.Export(ctx, req) + if err != nil { + t.Errorf(`Unexpected error: %s`, err) + } + assert.Equal(t, 1, len(mockTransmission.Events)) + event := mockTransmission.Events[0] + assert.Equal(t, "my-user-agent", event.Data["meta.refinery.incoming_user_agent"]) + + mockTransmission.Flush() + assert.Equal(t, 0, len(router.Collector.(*collect.MockCollector).Spans)) + mockCollector.Flush() + }) + + t.Run("logs record incoming user agent - HTTP", func(t *testing.T) { + req := &collectorlogs.ExportLogsServiceRequest{ + ResourceLogs: []*logs.ResourceLogs{{ + ScopeLogs: []*logs.ScopeLogs{{ + LogRecords: createLogsRecords(), + }}, + }}, + } + body, err := protojson.Marshal(req) + if err != nil { + t.Error(err) + } + + request, _ := http.NewRequest("POST", "/v1/logs", bytes.NewReader(body)) + request.Header = http.Header{} + request.Header.Set("content-type", "application/json") + request.Header.Set("x-honeycomb-team", legacyAPIKey) + request.Header.Set("x-honeycomb-dataset", "dataset") + request.Header.Set("user-agent", "my-user-agent") + + w := httptest.NewRecorder() + router.postOTLPLogs(w, request) + assert.Equal(t, w.Code, http.StatusOK) + + assert.Equal(t, 1, len(mockTransmission.Events)) + event := mockTransmission.Events[0] + assert.Equal(t, "my-user-agent", event.Data["meta.refinery.incoming_user_agent"]) + + mockTransmission.Flush() + assert.Equal(t, 0, len(router.Collector.(*collect.MockCollector).Spans)) + mockCollector.Flush() + }) } func createLogsRecords() []*logs.LogRecord { diff --git a/route/otlp_trace.go b/route/otlp_trace.go index c0137b0a76..8fcbdaae7c 100644 --- a/route/otlp_trace.go +++ b/route/otlp_trace.go @@ -38,7 +38,7 @@ func (r *Router) postOTLPTrace(w http.ResponseWriter, req *http.Request) { return } - if err := r.processOTLPRequest(req.Context(), result.Batches, keyToUse); err != nil { + if err := r.processOTLPRequest(req.Context(), result.Batches, keyToUse, ri.UserAgent); err != nil { r.handleOTLPFailureResponse(w, req, huskyotlp.OTLPError{Message: err.Error(), HTTPStatusCode: http.StatusInternalServerError}) return } @@ -74,7 +74,7 @@ func (t *TraceServer) Export(ctx context.Context, req *collectortrace.ExportTrac return nil, huskyotlp.AsGRPCError(err) } - if err := t.router.processOTLPRequest(ctx, result.Batches, keyToUse); err != nil { + if err := t.router.processOTLPRequest(ctx, result.Batches, keyToUse, ri.UserAgent); err != nil { return nil, huskyotlp.AsGRPCError(err) } diff --git a/route/otlp_trace_test.go b/route/otlp_trace_test.go index 93fbb390e6..c008d61712 100644 --- a/route/otlp_trace_test.go +++ b/route/otlp_trace_test.go @@ -498,6 +498,57 @@ func TestOTLPHandler(t *testing.T) { assert.Equal(t, 0, len(mockTransmission.Events)) mockTransmission.Flush() }) + + t.Run("spans record incoming user agent - gRPC", func(t *testing.T) { + md := metadata.New(map[string]string{"x-honeycomb-team": legacyAPIKey, "x-honeycomb-dataset": "ds", "user-agent": "my-user-agent"}) + ctx := metadata.NewIncomingContext(context.Background(), md) + + req := &collectortrace.ExportTraceServiceRequest{ + ResourceSpans: []*trace.ResourceSpans{{ + ScopeSpans: []*trace.ScopeSpans{{ + Spans: helperOTLPRequestSpansWithStatus(), + }}, + }}, + } + traceServer := NewTraceServer(router) + _, err := traceServer.Export(ctx, req) + if err != nil { + t.Errorf(`Unexpected error: %s`, err) + } + assert.Equal(t, 2, len(mockTransmission.Events)) + event := mockTransmission.Events[0] + assert.Equal(t, "my-user-agent", event.Data["meta.refinery.incoming_user_agent"]) + mockTransmission.Flush() + }) + + t.Run("spans record incoming user agent - HTTP", func(t *testing.T) { + req := &collectortrace.ExportTraceServiceRequest{ + ResourceSpans: []*trace.ResourceSpans{{ + ScopeSpans: []*trace.ScopeSpans{{ + Spans: helperOTLPRequestSpansWithStatus(), + }}, + }}, + } + body, err := protojson.Marshal(req) + if err != nil { + t.Error(err) + } + + request, _ := http.NewRequest("POST", "/v1/traces", bytes.NewReader(body)) + request.Header = http.Header{} + request.Header.Set("content-type", "application/json") + request.Header.Set("x-honeycomb-team", legacyAPIKey) + request.Header.Set("x-honeycomb-dataset", "dataset") + request.Header.Set("user-agent", "my-user-agent") + + w := httptest.NewRecorder() + router.postOTLPTrace(w, request) + + assert.Equal(t, 2, len(mockTransmission.Events)) + event := mockTransmission.Events[0] + assert.Equal(t, "my-user-agent", event.Data["meta.refinery.incoming_user_agent"]) + mockTransmission.Flush() + }) } func helperOTLPRequestSpansWithoutStatus() []*trace.Span { diff --git a/route/route.go b/route/route.go index ccafc5f7bf..12d5dda703 100644 --- a/route/route.go +++ b/route/route.go @@ -383,6 +383,7 @@ func (r *Router) event(w http.ResponseWriter, req *http.Request) { r.handlerReturnWithError(w, ErrReqToEvent, err) return } + addIncomingUserAgent(ev, req) reqID := req.Context().Value(types.RequestIDContextKey{}) err = r.processEvent(ev, reqID) @@ -491,6 +492,7 @@ func (r *Router) batch(w http.ResponseWriter, req *http.Request) { Data: bev.Data, } + addIncomingUserAgent(ev, req) err = r.processEvent(ev, reqID) var resp BatchResponse @@ -517,7 +519,8 @@ func (r *Router) batch(w http.ResponseWriter, req *http.Request) { func (router *Router) processOTLPRequest( ctx context.Context, batches []huskyotlp.Batch, - apiKey string) error { + apiKey string, + incomingUserAgent string) error { var requestID types.RequestIDContextKey apiHost := router.Config.GetHoneycombAPI() @@ -540,6 +543,7 @@ func (router *Router) processOTLPRequest( Timestamp: ev.Timestamp, Data: ev.Attributes, } + event.Data["meta.refinery.incoming_user_agent"] = incomingUserAgent if err = router.processEvent(event, requestID); err != nil { router.Logger.Error().Logf("Error processing event: " + err.Error()) } @@ -1052,3 +1056,9 @@ func extractTraceID(traceIdFieldNames []string, ev *types.Event) string { return "" } + +func addIncomingUserAgent(ev *types.Event, req *http.Request) { + if userAgent := req.Header.Get("User-Agent"); userAgent != "" { + ev.Data["meta.refinery.incoming_user_agent"] = userAgent + } +} From db9d350b36102e7360e9ed909bd92e58d99667ef Mon Sep 17 00:00:00 2001 From: Mike Goldsmth Date: Wed, 2 Oct 2024 13:53:31 +0100 Subject: [PATCH 2/5] add defer to restore allowed keys after test --- route/otlp_trace_test.go | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/route/otlp_trace_test.go b/route/otlp_trace_test.go index c008d61712..ce318944c2 100644 --- a/route/otlp_trace_test.go +++ b/route/otlp_trace_test.go @@ -484,6 +484,13 @@ func TestOTLPHandler(t *testing.T) { ReceiveKeys: []string{}, AcceptOnlyListedKeys: true, } + defer func() { + router.Config.(*config.MockConfig).GetAccessKeyConfigVal = config.AccessKeyConfig{ + ReceiveKeys: []string{legacyAPIKey}, + AcceptOnlyListedKeys: false, + } + }() + req := &collectortrace.ExportTraceServiceRequest{ ResourceSpans: []*trace.ResourceSpans{{ ScopeSpans: []*trace.ScopeSpans{{ From 8550dad0bb12f1ff78f1a97c983bc40a631667c7 Mon Sep 17 00:00:00 2001 From: Mike Goldsmth Date: Wed, 2 Oct 2024 14:03:32 +0100 Subject: [PATCH 3/5] clean up a little --- route/route.go | 14 ++++++++++---- 1 file changed, 10 insertions(+), 4 deletions(-) diff --git a/route/route.go b/route/route.go index 12d5dda703..f6f15df76c 100644 --- a/route/route.go +++ b/route/route.go @@ -383,7 +383,7 @@ func (r *Router) event(w http.ResponseWriter, req *http.Request) { r.handlerReturnWithError(w, ErrReqToEvent, err) return } - addIncomingUserAgent(ev, req) + addIncomingUserAgentFromRequest(ev, req) reqID := req.Context().Value(types.RequestIDContextKey{}) err = r.processEvent(ev, reqID) @@ -492,7 +492,7 @@ func (r *Router) batch(w http.ResponseWriter, req *http.Request) { Data: bev.Data, } - addIncomingUserAgent(ev, req) + addIncomingUserAgentFromRequest(ev, req) err = r.processEvent(ev, reqID) var resp BatchResponse @@ -543,7 +543,7 @@ func (router *Router) processOTLPRequest( Timestamp: ev.Timestamp, Data: ev.Attributes, } - event.Data["meta.refinery.incoming_user_agent"] = incomingUserAgent + addIncomingUserAgent(event, incomingUserAgent) if err = router.processEvent(event, requestID); err != nil { router.Logger.Error().Logf("Error processing event: " + err.Error()) } @@ -1057,8 +1057,14 @@ func extractTraceID(traceIdFieldNames []string, ev *types.Event) string { return "" } -func addIncomingUserAgent(ev *types.Event, req *http.Request) { +func addIncomingUserAgentFromRequest(ev *types.Event, req *http.Request) { if userAgent := req.Header.Get("User-Agent"); userAgent != "" { + addIncomingUserAgent(ev, userAgent) + } +} + +func addIncomingUserAgent(ev *types.Event, userAgent string) { + if userAgent != "" { ev.Data["meta.refinery.incoming_user_agent"] = userAgent } } From b90128645022242e50cac6f97889fe62f504d5c7 Mon Sep 17 00:00:00 2001 From: Mike Goldsmth Date: Wed, 2 Oct 2024 19:28:44 +0100 Subject: [PATCH 4/5] only get user agent once when handling batches --- route/route.go | 11 +++++------ 1 file changed, 5 insertions(+), 6 deletions(-) diff --git a/route/route.go b/route/route.go index f6f15df76c..370010cb46 100644 --- a/route/route.go +++ b/route/route.go @@ -383,7 +383,7 @@ func (r *Router) event(w http.ResponseWriter, req *http.Request) { r.handlerReturnWithError(w, ErrReqToEvent, err) return } - addIncomingUserAgentFromRequest(ev, req) + addIncomingUserAgent(ev, getUserAgentFromRequest(req)) reqID := req.Context().Value(types.RequestIDContextKey{}) err = r.processEvent(ev, reqID) @@ -479,6 +479,7 @@ func (r *Router) batch(w http.ResponseWriter, req *http.Request) { r.handlerReturnWithError(w, ErrReqToEvent, err) } + userAgent := getUserAgentFromRequest(req) batchedResponses := make([]*BatchResponse, 0, len(batchedEvents)) for _, bev := range batchedEvents { ev := &types.Event{ @@ -492,7 +493,7 @@ func (r *Router) batch(w http.ResponseWriter, req *http.Request) { Data: bev.Data, } - addIncomingUserAgentFromRequest(ev, req) + addIncomingUserAgent(ev, userAgent) err = r.processEvent(ev, reqID) var resp BatchResponse @@ -1057,10 +1058,8 @@ func extractTraceID(traceIdFieldNames []string, ev *types.Event) string { return "" } -func addIncomingUserAgentFromRequest(ev *types.Event, req *http.Request) { - if userAgent := req.Header.Get("User-Agent"); userAgent != "" { - addIncomingUserAgent(ev, userAgent) - } +func getUserAgentFromRequest(req *http.Request) string { + return req.Header.Get("User-Agent") } func addIncomingUserAgent(ev *types.Event, userAgent string) { From 1b0d17acfb4798215e4079f7555ef50d5fe3688d Mon Sep 17 00:00:00 2001 From: Mike Goldsmth Date: Thu, 3 Oct 2024 14:20:36 +0100 Subject: [PATCH 5/5] update expected test span size --- app/app_test.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/app/app_test.go b/app/app_test.go index dda2698bce..57a3be7ca1 100644 --- a/app/app_test.go +++ b/app/app_test.go @@ -780,7 +780,7 @@ func TestPeerRouting_TraceLocalityDisabled(t *testing.T) { "meta.refinery.min_span": true, "meta.annotation_type": types.SpanAnnotationTypeUnknown, "meta.refinery.root": false, - "meta.refinery.span_data_size": 157, + "meta.refinery.span_data_size": 175, }, Metadata: map[string]any{ "api_host": "http://localhost:17001",