diff --git a/config/core/configmaps/observability.yaml b/config/core/configmaps/observability.yaml index fd0f973e2a46..9edbea191e30 100644 --- a/config/core/configmaps/observability.yaml +++ b/config/core/configmaps/observability.yaml @@ -22,7 +22,7 @@ metadata: app.kubernetes.io/component: observability app.kubernetes.io/version: devel annotations: - knative.dev/example-checksum: "f183bbc6" + knative.dev/example-checksum: "59abacb5" data: _example: | ################################ @@ -80,7 +80,7 @@ data: # PodIP string // IP of the pod hosting the revision # } # - logging.request-log-template: '{"httpRequest": {"requestMethod": "{{.Request.Method}}", "requestUrl": "{{js .Request.RequestURI}}", "requestSize": "{{.Request.ContentLength}}", "status": {{.Response.Code}}, "responseSize": "{{.Response.Size}}", "userAgent": "{{js .Request.UserAgent}}", "remoteIp": "{{js .Request.RemoteAddr}}", "serverIp": "{{.Revision.PodIP}}", "referer": "{{js .Request.Referer}}", "latency": "{{.Response.Latency}}s", "protocol": "{{.Request.Proto}}"}, "traceId": "{{index .Request.Header "X-B3-Traceid"}}"}' + logging.request-log-template: '{"httpRequest": {"requestMethod": "{{.Request.Method}}", "requestUrl": "{{js .Request.RequestURI}}", "requestSize": "{{.Request.ContentLength}}", "status": {{.Response.Code}}, "responseSize": "{{.Response.Size}}", "userAgent": "{{js .Request.UserAgent}}", "remoteIp": "{{js .Request.RemoteAddr}}", "serverIp": "{{.Revision.PodIP}}", "referer": "{{js .Request.Referer}}", "latency": "{{.Response.Latency}}s", "protocol": "{{.Request.Proto}}"}, "traceId": "{{.TraceID}}"}' # If true, the request logging will be enabled. logging.enable-request-log: "false" diff --git a/pkg/http/request_log.go b/pkg/http/request_log.go index 1803bb7e6e96..fed5748b0341 100644 --- a/pkg/http/request_log.go +++ b/pkg/http/request_log.go @@ -66,6 +66,7 @@ type RequestLogTemplateInput struct { Request *http.Request Response *RequestLogResponse Revision *RequestLogRevision + TraceID string // Extracted from W3C Trace Context (traceparent) or B3 (X-B3-TraceId) headers } // RequestLogTemplateInputGetter defines a function returning the input to pass to a request log writer. @@ -79,6 +80,7 @@ func RequestLogTemplateInputGetterFromRevision(rev *RequestLogRevision) RequestL Request: req, Response: resp, Revision: rev, + TraceID: ExtractTraceID(req.Header), } } } diff --git a/pkg/http/request_log_test.go b/pkg/http/request_log_test.go index 0895377fd931..bd99e23de20c 100644 --- a/pkg/http/request_log_test.go +++ b/pkg/http/request_log_test.go @@ -258,7 +258,7 @@ func BenchmarkRequestLogHandlerNoTemplate(b *testing.B) { func BenchmarkRequestLogHandlerDefaultTemplate(b *testing.B) { // Taken from config-observability.yaml - tpl := `{"httpRequest": {"requestMethod": "{{.Request.Method}}", "requestUrl": "{{js .Request.RequestURI}}", "requestSize": "{{.Request.ContentLength}}", "status": {{.Response.Code}}, "responseSize": "{{.Response.Size}}", "userAgent": "{{js .Request.UserAgent}}", "remoteIp": "{{js .Request.RemoteAddr}}", "serverIp": "{{.Revision.PodIP}}", "referer": "{{js .Request.Referer}}", "latency": "{{.Response.Latency}}s", "protocol": "{{.Request.Proto}}"}, "traceId": "{{index .Request.Header "X-B3-Traceid"}}"}` + tpl := `{"httpRequest": {"requestMethod": "{{.Request.Method}}", "requestUrl": "{{js .Request.RequestURI}}", "requestSize": "{{.Request.ContentLength}}", "status": {{.Response.Code}}, "responseSize": "{{.Response.Size}}", "userAgent": "{{js .Request.UserAgent}}", "remoteIp": "{{js .Request.RemoteAddr}}", "serverIp": "{{.Revision.PodIP}}", "referer": "{{js .Request.Referer}}", "latency": "{{.Response.Latency}}s", "protocol": "{{.Request.Proto}}"}, "traceId": "{{.TraceID}}"}` handler, err := NewRequestLogHandler(baseHandler, io.Discard, tpl, defaultInputGetter, false) if err != nil { b.Fatal("Failed to create handler:", err) diff --git a/pkg/http/trace.go b/pkg/http/trace.go new file mode 100644 index 000000000000..d823ad375360 --- /dev/null +++ b/pkg/http/trace.go @@ -0,0 +1,41 @@ +/* +Copyright 2025 The Knative Authors + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package http + +import ( + "net/http" + "strings" +) + +// ExtractTraceID extracts the trace ID from the request headers. +// It supports both W3C Trace Context (traceparent) and B3 (X-B3-TraceId) formats. +func ExtractTraceID(h http.Header) string { + //nolint:canonicalheader + if traceparent := h.Get("traceparent"); traceparent != "" { + parts := strings.SplitN(traceparent, "-", 3) + if len(parts) >= 2 { + return parts[1] + } + } + + //nolint:canonicalheader + if b3TraceID := h.Get("X-B3-TraceId"); b3TraceID != "" { + return b3TraceID + } + + return "" +} diff --git a/pkg/http/trace_integration_test.go b/pkg/http/trace_integration_test.go new file mode 100644 index 000000000000..1e1f8c39a33e --- /dev/null +++ b/pkg/http/trace_integration_test.go @@ -0,0 +1,169 @@ +/* +Copyright 2025 The Knative Authors + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package http + +import ( + "bytes" + "net/http" + "net/http/httptest" + "strings" + "testing" +) + +// TestTraceIDInRequestLog verifies that trace IDs are properly extracted +// and included in request logs for both W3C Trace Context and B3 formats. +func TestTraceIDInRequestLog(t *testing.T) { + tests := []struct { + name string + headers map[string]string + expectedTraceID string + description string + }{{ + name: "W3C Trace Context (OpenTelemetry)", + headers: map[string]string{ + "traceparent": "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01", + }, + expectedTraceID: "4bf92f3577b34da6a3ce929d0e0e4736", + description: "Should extract trace ID from W3C traceparent header", + }, { + name: "B3 Format (Legacy)", + headers: map[string]string{ + "X-B3-TraceId": "80f198ee56343ba864fe8b2a57d3eff7", + "X-B3-SpanId": "00f067aa0ba902b7", + }, + expectedTraceID: "80f198ee56343ba864fe8b2a57d3eff7", + description: "Should extract trace ID from B3 X-B3-TraceId header", + }, { + name: "Both formats present (W3C preferred)", + headers: map[string]string{ + "traceparent": "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01", + "X-B3-TraceId": "80f198ee56343ba864fe8b2a57d3eff7", + }, + expectedTraceID: "0af7651916cd43dd8448eb211c80319c", + description: "Should prefer W3C Trace Context over B3 when both are present", + }, { + name: "No trace headers", + headers: map[string]string{}, + expectedTraceID: "", + description: "Should return empty string when no trace headers present", + }} + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + var logOutput bytes.Buffer + + // Use the default template format with TraceID field + template := `{"traceId": "{{.TraceID}}", "status": {{.Response.Code}}}` + + handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(http.StatusOK) + }) + + rev := &RequestLogRevision{ + Name: "test-rev", + Namespace: "test-ns", + Service: "test-svc", + } + + logHandler, err := NewRequestLogHandler( + handler, + &logOutput, + template, + RequestLogTemplateInputGetterFromRevision(rev), + false, + ) + if err != nil { + t.Fatal("Failed to create log handler:", err) + } + + req := httptest.NewRequest(http.MethodGet, "http://example.com/test", nil) + for k, v := range tt.headers { + req.Header.Set(k, v) + } + + resp := httptest.NewRecorder() + logHandler.ServeHTTP(resp, req) + + logLine := logOutput.String() + if tt.expectedTraceID != "" { + expectedLog := `"traceId": "` + tt.expectedTraceID + `"` + if !strings.Contains(logLine, expectedLog) { + t.Errorf("%s\nExpected log to contain: %s\nGot: %s", tt.description, expectedLog, logLine) + } + } else { + // When no trace ID, should have empty string + expectedLog := `"traceId": ""` + if !strings.Contains(logLine, expectedLog) { + t.Errorf("%s\nExpected log to contain empty traceId\nGot: %s", tt.description, logLine) + } + } + }) + } +} + +// TestRequestLogTemplateWithTraceID tests the full request log template +// using the same format as production (config-observability.yaml). +func TestRequestLogTemplateWithTraceID(t *testing.T) { + var logOutput bytes.Buffer + + // Use the production template format + template := `{"httpRequest": {"requestMethod": "{{.Request.Method}}", "status": {{.Response.Code}}}, "traceId": "{{.TraceID}}"}` + + handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(http.StatusOK) + }) + + rev := &RequestLogRevision{ + Name: "my-service-abc123", + Namespace: "default", + Service: "my-service", + } + + logHandler, err := NewRequestLogHandler( + handler, + &logOutput, + template, + RequestLogTemplateInputGetterFromRevision(rev), + false, + ) + if err != nil { + t.Fatal("Failed to create log handler:", err) + } + + // Test with W3C Trace Context + req := httptest.NewRequest(http.MethodPost, "http://example.com/api", nil) + //nolint:canonicalheader + req.Header.Set("traceparent", "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01") + + resp := httptest.NewRecorder() + logHandler.ServeHTTP(resp, req) + + logLine := logOutput.String() + + // Verify all expected fields are present + expectedFields := []string{ + `"requestMethod": "POST"`, + `"status": 200`, + `"traceId": "4bf92f3577b34da6a3ce929d0e0e4736"`, + } + + for _, expected := range expectedFields { + if !strings.Contains(logLine, expected) { + t.Errorf("Expected log to contain: %s\nGot: %s", expected, logLine) + } + } +} diff --git a/pkg/http/trace_test.go b/pkg/http/trace_test.go new file mode 100644 index 000000000000..828ed96bd1fd --- /dev/null +++ b/pkg/http/trace_test.go @@ -0,0 +1,141 @@ +/* +Copyright 2025 The Knative Authors + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package http + +import ( + "net/http" + "testing" +) + +func TestExtractTraceID(t *testing.T) { + tests := []struct { + name string + headers map[string]string + want string + }{{ + name: "W3C Trace Context traceparent", + headers: map[string]string{ + "traceparent": "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01", + }, + want: "4bf92f3577b34da6a3ce929d0e0e4736", + }, { + name: "W3C Trace Context with tracestate", + headers: map[string]string{ + "traceparent": "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01", + "tracestate": "congo=t61rcWkgMzE", + }, + want: "0af7651916cd43dd8448eb211c80319c", + }, { + name: "B3 TraceId (uppercase)", + headers: map[string]string{ + "X-B3-TraceId": "80f198ee56343ba864fe8b2a57d3eff7", + }, + want: "80f198ee56343ba864fe8b2a57d3eff7", + }, { + name: "B3 Traceid (lowercase 'id')", + headers: map[string]string{ + "X-B3-Traceid": "463ac35c9f6413ad48485a3953bb6124", + }, + want: "463ac35c9f6413ad48485a3953bb6124", + }, { + name: "W3C Trace Context preferred over B3", + headers: map[string]string{ + "traceparent": "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01", + "X-B3-TraceId": "80f198ee56343ba864fe8b2a57d3eff7", + }, + want: "4bf92f3577b34da6a3ce929d0e0e4736", // W3C takes precedence + }, { + name: "B3 short format (8 bytes)", + headers: map[string]string{ + "X-B3-TraceId": "463ac35c9f6413ad", + }, + want: "463ac35c9f6413ad", + }, { + name: "No trace headers", + headers: map[string]string{ + "Content-Type": "application/json", + }, + want: "", + }, { + name: "Empty headers", + headers: map[string]string{}, + want: "", + }, { + name: "Invalid traceparent format", + headers: map[string]string{ + "traceparent": "invalid", + }, + want: "", + }, { + name: "Traceparent with only version", + headers: map[string]string{ + "traceparent": "00", + }, + want: "", + }} + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + header := make(http.Header) + for k, v := range tt.headers { + header.Set(k, v) + } + + got := ExtractTraceID(header) + if got != tt.want { + t.Errorf("ExtractTraceID() = %v, want %v", got, tt.want) + } + }) + } +} + +func BenchmarkExtractTraceID(b *testing.B) { + benchmarks := []struct { + name string + headers map[string]string + }{{ + name: "W3C Trace Context", + headers: map[string]string{ + "traceparent": "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01", + }, + }, { + name: "B3 TraceId", + headers: map[string]string{ + "X-B3-TraceId": "80f198ee56343ba864fe8b2a57d3eff7", + }, + }, { + name: "Both formats (W3C preferred)", + headers: map[string]string{ + "traceparent": "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01", + "X-B3-TraceId": "80f198ee56343ba864fe8b2a57d3eff7", + }, + }} + + for _, bm := range benchmarks { + b.Run(bm.name, func(b *testing.B) { + header := make(http.Header) + for k, v := range bm.headers { + header.Set(k, v) + } + + b.ResetTimer() + for range b.N { + ExtractTraceID(header) + } + }) + } +} diff --git a/pkg/observability/config.go b/pkg/observability/config.go index 133724b39386..e512737b5b4e 100644 --- a/pkg/observability/config.go +++ b/pkg/observability/config.go @@ -31,7 +31,7 @@ const ( DefaultLogURLTemplate = "" // DefaultRequestLogTemplate is the default format for emitting request logs. - DefaultRequestLogTemplate = `{"httpRequest": {"requestMethod": "{{.Request.Method}}", "requestUrl": "{{js .Request.RequestURI}}", "requestSize": "{{.Request.ContentLength}}", "status": {{.Response.Code}}, "responseSize": "{{.Response.Size}}", "userAgent": "{{js .Request.UserAgent}}", "remoteIp": "{{js .Request.RemoteAddr}}", "serverIp": "{{.Revision.PodIP}}", "referer": "{{js .Request.Referer}}", "latency": "{{.Response.Latency}}s", "protocol": "{{.Request.Proto}}"}, "traceId": "{{index .Request.Header "X-B3-Traceid"}}"}` + DefaultRequestLogTemplate = `{"httpRequest": {"requestMethod": "{{.Request.Method}}", "requestUrl": "{{js .Request.RequestURI}}", "requestSize": "{{.Request.ContentLength}}", "status": {{.Response.Code}}, "responseSize": "{{.Response.Size}}", "userAgent": "{{js .Request.UserAgent}}", "remoteIp": "{{js .Request.RemoteAddr}}", "serverIp": "{{.Revision.PodIP}}", "referer": "{{js .Request.Referer}}", "latency": "{{.Response.Latency}}s", "protocol": "{{.Request.Proto}}"}, "traceId": "{{.TraceID}}"}` // ReqLogTemplateKey is the CM key for the request log template. RequestLogTemplateKey = "logging.request-log-template" diff --git a/test/config/ytt/core/overlay-config-observability.yaml b/test/config/ytt/core/overlay-config-observability.yaml index db880222cbd0..49bb18a296fe 100644 --- a/test/config/ytt/core/overlay-config-observability.yaml +++ b/test/config/ytt/core/overlay-config-observability.yaml @@ -5,7 +5,7 @@ --- #@overlay/match-child-defaults missing_ok=True data: - logging.request-log-template: '{"httpRequest": {"requestMethod": "{{.Request.Method}}", "requestUrl": "{{js .Request.RequestURI}}", "requestSize": "{{.Request.ContentLength}}", "status": {{.Response.Code}}, "responseSize": "{{.Response.Size}}", "userAgent": "{{js .Request.UserAgent}}", "remoteIp": "{{js .Request.RemoteAddr}}", "serverIp": "{{.Revision.PodIP}}", "referer": "{{js .Request.Referer}}", "latency": "{{.Response.Latency}}s", "protocol": "{{.Request.Proto}}"}, "traceId": "{{index .Request.Header "X-B3-Traceid"}}"}' + logging.request-log-template: '{"httpRequest": {"requestMethod": "{{.Request.Method}}", "requestUrl": "{{js .Request.RequestURI}}", "requestSize": "{{.Request.ContentLength}}", "status": {{.Response.Code}}, "responseSize": "{{.Response.Size}}", "userAgent": "{{js .Request.UserAgent}}", "remoteIp": "{{js .Request.RemoteAddr}}", "serverIp": "{{.Revision.PodIP}}", "referer": "{{js .Request.Referer}}", "latency": "{{.Response.Latency}}s", "protocol": "{{.Request.Proto}}"}, "traceId": "{{.TraceID}}"}' logging.enable-probe-request-log: "true" logging.enable-request-log: "true" diff --git a/test/conformance/runtime/header_test.go b/test/conformance/runtime/header_test.go index 51642d99f31e..e52071e36a24 100644 --- a/test/conformance/runtime/header_test.go +++ b/test/conformance/runtime/header_test.go @@ -93,7 +93,9 @@ func TestShouldHaveHeadersSet(t *testing.T) { // We expect the value to be a 64-bit or 128-bit hex string "x-b3-traceid": regexp.MustCompile("[0-9a-f]{16}|[0-9a-f]{32}"), - "traceparent": regexp.MustCompile("[0-9]{2}-[0-9a-f]{32}-[0-9a-f]{16}-[0-9]{2}"), + // Support W3C Trace Context (OpenTelemetry standard) + // Format: version-trace-id-span-id-trace-flags (00-<32-hex>-<16-hex>-<2-hex>) + "traceparent": regexp.MustCompile("[0-9a-f]{2}-[0-9a-f]{32}-[0-9a-f]{16}-[0-9a-f]{2}"), // "x-b3-parentspanid" and "x-b3-sampled" are often present for tracing, but are not // required for tracing so we do not validate them. diff --git a/test/e2e/logging_test.go b/test/e2e/logging_test.go index 9f967a7a234d..ba5b89a01138 100644 --- a/test/e2e/logging_test.go +++ b/test/e2e/logging_test.go @@ -46,11 +46,9 @@ import ( v1test "knative.dev/serving/test/v1" ) -const template = `{"httpRequest": {"requestMethod": "{{.Request.Method}}", "requestUrl": "{{js .Request.RequestURI}}", "requestSize": "{{.Request.ContentLength}}", "status": {{.Response.Code}}, "responseSize": "{{.Response.Size}}", "userAgent": "{{js .Request.UserAgent}}", "remoteIp": "{{js .Request.RemoteAddr}}", "serverIp": "{{.Revision.PodIP}}", "referer": "{{js .Request.Referer}}", "latency": "{{.Response.Latency}}s", "protocol": "{{.Request.Proto}}"}, "traceId": "{{index .Request.Header "X-B3-Traceid"}}"}` +const template = `{"httpRequest": {"requestMethod": "{{.Request.Method}}", "requestUrl": "{{js .Request.RequestURI}}", "requestSize": "{{.Request.ContentLength}}", "status": {{.Response.Code}}, "responseSize": "{{.Response.Size}}", "userAgent": "{{js .Request.UserAgent}}", "remoteIp": "{{js .Request.RemoteAddr}}", "serverIp": "{{.Revision.PodIP}}", "referer": "{{js .Request.Referer}}", "latency": "{{.Response.Latency}}s", "protocol": "{{.Request.Proto}}"}, "traceId": "{{.TraceID}}"}` func TestRequestLogs(t *testing.T) { - t.Skip("skipping test while we implement OTel into the queue-proxy") - t.Parallel() clients := Setup(t)