Skip to content

Commit 68ef4ab

Browse files
joliveirinhajoliveirinha
committed
TUN-7197: Add connIndex tag to debug messages of incoming requests
1 parent ea6fe12 commit 68ef4ab

File tree

10 files changed

+47
-36
lines changed

10 files changed

+47
-36
lines changed

‎connection/connection.go‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -142,6 +142,7 @@ type TCPRequest struct {
142142
LBProbe bool
143143
FlowID string
144144
CfTraceID string
145+
ConnIndex uint8
145146
}
146147

147148
// ReadWriteAcker is a readwriter with the ability to Acknowledge to the downstream (edge) that the origin has

‎connection/h2mux.go‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -196,7 +196,7 @@ func (h *h2muxConnection) ServeStream(stream *h2mux.MuxedStream) error {
196196
return err
197197
}
198198

199-
err = originProxy.ProxyHTTP(respWriter, tracing.NewTracedHTTPRequest(req, h.log), sourceConnectionType == TypeWebsocket)
199+
err = originProxy.ProxyHTTP(respWriter, tracing.NewTracedHTTPRequest(req, h.connIndex, h.log), sourceConnectionType == TypeWebsocket)
200200
if err != nil {
201201
respWriter.WriteErrorResponse()
202202
}

‎connection/http2.go‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -129,7 +129,7 @@ func (c *HTTP2Connection) ServeHTTP(w http.ResponseWriter, r *http.Request) {
129129
case TypeWebsocket, TypeHTTP:
130130
stripWebsocketUpgradeHeader(r)
131131
// Check for tracing on request
132-
tr := tracing.NewTracedHTTPRequest(r, c.log)
132+
tr := tracing.NewTracedHTTPRequest(r, c.connIndex, c.log)
133133
if err := originProxy.ProxyHTTP(respWriter, tr, connType == TypeWebsocket); err != nil {
134134
requestErr = fmt.Errorf("Failed to proxy HTTP: %w", err)
135135
}
@@ -147,6 +147,7 @@ func (c *HTTP2Connection) ServeHTTP(w http.ResponseWriter, r *http.Request) {
147147
CFRay: FindCfRayHeader(r),
148148
LBProbe: IsLBProbeRequest(r),
149149
CfTraceID: r.Header.Get(tracing.TracerContextName),
150+
ConnIndex: c.connIndex,
150151
})
151152

152153
default:

‎connection/quic.go‎

Lines changed: 6 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -60,6 +60,7 @@ type QUICConnection struct {
6060
packetRouter *ingress.PacketRouter
6161
controlStreamHandler ControlStreamHandler
6262
connOptions *tunnelpogs.ConnectionOptions
63+
connIndex uint8
6364
}
6465

6566
// NewQUICConnection returns a new instance of QUICConnection.
@@ -106,6 +107,7 @@ func NewQUICConnection(
106107
packetRouter: packetRouter,
107108
controlStreamHandler: controlStreamHandler,
108109
connOptions: connOptions,
110+
connIndex: connIndex,
109111
}, nil
110112
}
111113

@@ -258,7 +260,7 @@ func (q *QUICConnection) dispatchRequest(ctx context.Context, stream *quicpogs.R
258260

259261
switch request.Type {
260262
case quicpogs.ConnectionTypeHTTP, quicpogs.ConnectionTypeWebsocket:
261-
tracedReq, err := buildHTTPRequest(ctx, request, stream, q.logger)
263+
tracedReq, err := buildHTTPRequest(ctx, request, stream, q.connIndex, q.logger)
262264
if err != nil {
263265
return err, false
264266
}
@@ -272,6 +274,7 @@ func (q *QUICConnection) dispatchRequest(ctx context.Context, stream *quicpogs.R
272274
Dest: request.Dest,
273275
FlowID: metadata[QUICMetadataFlowID],
274276
CfTraceID: metadata[tracing.TracerContextName],
277+
ConnIndex: q.connIndex,
275278
}), rwa.connectResponseSent
276279
default:
277280
return errors.Errorf("unsupported error type: %s", request.Type), false
@@ -435,6 +438,7 @@ func buildHTTPRequest(
435438
ctx context.Context,
436439
connectRequest *quicpogs.ConnectRequest,
437440
body io.ReadCloser,
441+
connIndex uint8,
438442
log *zerolog.Logger,
439443
) (*tracing.TracedHTTPRequest, error) {
440444
metadata := connectRequest.MetadataMap()
@@ -478,7 +482,7 @@ func buildHTTPRequest(
478482
stripWebsocketUpgradeHeader(req)
479483

480484
// Check for tracing on request
481-
tracedReq := tracing.NewTracedHTTPRequest(req, log)
485+
tracedReq := tracing.NewTracedHTTPRequest(req, connIndex, log)
482486
return tracedReq, err
483487
}
484488

‎connection/quic_test.go‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -485,7 +485,7 @@ func TestBuildHTTPRequest(t *testing.T) {
485485
for _, test := range tests {
486486
test := test // capture range variable
487487
t.Run(test.name, func(t *testing.T) {
488-
req, err := buildHTTPRequest(context.Background(), test.connectRequest, test.body, &log)
488+
req, err := buildHTTPRequest(context.Background(), test.connectRequest, test.body, 0, &log)
489489
assert.NoError(t, err)
490490
test.req = test.req.WithContext(req.Context())
491491
assert.Equal(t, test.req, req.Request)

‎orchestration/orchestrator_test.go‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -358,7 +358,7 @@ func proxyHTTP(originProxy connection.OriginProxy, hostname string) (*http.Respo
358358
return nil, err
359359
}
360360

361-
err = originProxy.ProxyHTTP(respWriter, tracing.NewTracedHTTPRequest(req, &log), false)
361+
err = originProxy.ProxyHTTP(respWriter, tracing.NewTracedHTTPRequest(req, 0, &log), false)
362362
if err != nil {
363363
return nil, err
364364
}
@@ -608,7 +608,7 @@ func TestPersistentConnection(t *testing.T) {
608608
respWriter, err := connection.NewHTTP2RespWriter(req, wsRespReadWriter, connection.TypeWebsocket, &log)
609609
require.NoError(t, err)
610610

611-
err = originProxy.ProxyHTTP(respWriter, tracing.NewTracedHTTPRequest(req, &log), true)
611+
err = originProxy.ProxyHTTP(respWriter, tracing.NewTracedHTTPRequest(req, 0, &log), true)
612612
require.NoError(t, err)
613613
}()
614614

‎proxy/proxy.go‎

Lines changed: 19 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,7 @@ const (
2828
LogFieldRule = "ingressRule"
2929
LogFieldOriginService = "originService"
3030
LogFieldFlowID = "flowID"
31+
LogFieldConnIndex = "connIndex"
3132

3233
trailerHeaderName = "Trailer"
3334
)
@@ -94,9 +95,10 @@ func (p *Proxy) ProxyHTTP(
9495
trace.WithAttributes(attribute.String("req-host", req.Host)))
9596
rule, ruleNum := p.ingressRules.FindMatchingRule(req.Host, req.URL.Path)
9697
logFields := logFields{
97-
cfRay: cfRay,
98-
lbProbe: lbProbe,
99-
rule: ruleNum,
98+
cfRay: cfRay,
99+
lbProbe: lbProbe,
100+
rule: ruleNum,
101+
connIndex: tr.ConnIndex,
100102
}
101103
p.logRequest(req, logFields)
102104
ruleSpan.SetAttributes(attribute.Int("rule-num", ruleNum))
@@ -163,14 +165,14 @@ func (p *Proxy) ProxyTCP(
163165

164166
tracedCtx := tracing.NewTracedContext(serveCtx, req.CfTraceID, p.log)
165167

166-
p.log.Debug().Str(LogFieldFlowID, req.FlowID).Msg("tcp proxy stream started")
168+
p.log.Debug().Str(LogFieldFlowID, req.FlowID).Uint8(LogFieldConnIndex, req.ConnIndex).Msg("tcp proxy stream started")
167169

168170
if err := p.proxyStream(tracedCtx, rwa, req.Dest, p.warpRouting.Proxy); err != nil {
169171
p.logRequestError(err, req.CFRay, req.FlowID, "", ingress.ServiceWarpRouting)
170172
return err
171173
}
172174

173-
p.log.Debug().Str(LogFieldFlowID, req.FlowID).Msg("tcp proxy stream finished successfully")
175+
p.log.Debug().Str(LogFieldFlowID, req.FlowID).Uint8(LogFieldConnIndex, req.ConnIndex).Msg("tcp proxy stream finished successfully")
174176

175177
return nil
176178
}
@@ -320,10 +322,11 @@ func (p *Proxy) appendTagHeaders(r *http.Request) {
320322
}
321323

322324
type logFields struct {
323-
cfRay string
324-
lbProbe bool
325-
rule interface{}
326-
flowID string
325+
cfRay string
326+
lbProbe bool
327+
rule interface{}
328+
flowID string
329+
connIndex uint8
327330
}
328331

329332
func copyTrailers(w connection.ResponseWriter, response *http.Response) {
@@ -348,6 +351,7 @@ func (p *Proxy) logRequest(r *http.Request, fields logFields) {
348351
Str("host", r.Host).
349352
Str("path", r.URL.Path).
350353
Interface("rule", fields.rule).
354+
Uint8(LogFieldConnIndex, fields.connIndex).
351355
Msg("Inbound request")
352356

353357
if contentLen := r.ContentLength; contentLen == -1 {
@@ -360,18 +364,18 @@ func (p *Proxy) logRequest(r *http.Request, fields logFields) {
360364
func (p *Proxy) logOriginResponse(resp *http.Response, fields logFields) {
361365
responseByCode.WithLabelValues(strconv.Itoa(resp.StatusCode)).Inc()
362366
if fields.cfRay != "" {
363-
p.log.Debug().Msgf("CF-RAY: %s Status: %s served by ingress %d", fields.cfRay, resp.Status, fields.rule)
367+
p.log.Debug().Uint8(LogFieldConnIndex, fields.connIndex).Msgf("CF-RAY: %s Status: %s served by ingress %d", fields.cfRay, resp.Status, fields.rule)
364368
} else if fields.lbProbe {
365-
p.log.Debug().Msgf("Response to Load Balancer health check %s", resp.Status)
369+
p.log.Debug().Uint8(LogFieldConnIndex, fields.connIndex).Msgf("Response to Load Balancer health check %s", resp.Status)
366370
} else {
367-
p.log.Debug().Msgf("Status: %s served by ingress %v", resp.Status, fields.rule)
371+
p.log.Debug().Uint8(LogFieldConnIndex, fields.connIndex).Msgf("Status: %s served by ingress %v", resp.Status, fields.rule)
368372
}
369-
p.log.Debug().Msgf("CF-RAY: %s Response Headers %+v", fields.cfRay, resp.Header)
373+
p.log.Debug().Uint8(LogFieldConnIndex, fields.connIndex).Msgf("CF-RAY: %s Response Headers %+v", fields.cfRay, resp.Header)
370374

371375
if contentLen := resp.ContentLength; contentLen == -1 {
372-
p.log.Debug().Msgf("CF-RAY: %s Response content length unknown", fields.cfRay)
376+
p.log.Debug().Uint8(LogFieldConnIndex, fields.connIndex).Msgf("CF-RAY: %s Response content length unknown", fields.cfRay)
373377
} else {
374-
p.log.Debug().Msgf("CF-RAY: %s Response content length %d", fields.cfRay, contentLen)
378+
p.log.Debug().Uint8(LogFieldConnIndex, fields.connIndex).Msgf("CF-RAY: %s Response content length %d", fields.cfRay, contentLen)
375379
}
376380
}
377381

‎proxy/proxy_test.go‎

Lines changed: 6 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -170,7 +170,7 @@ func testProxyHTTP(proxy connection.OriginProxy) func(t *testing.T) {
170170
require.NoError(t, err)
171171

172172
log := zerolog.Nop()
173-
err = proxy.ProxyHTTP(responseWriter, tracing.NewTracedHTTPRequest(req, &log), false)
173+
err = proxy.ProxyHTTP(responseWriter, tracing.NewTracedHTTPRequest(req, 0, &log), false)
174174
require.NoError(t, err)
175175
for _, tag := range testTags {
176176
assert.Equal(t, tag.Value, req.Header.Get(TagHeaderNamePrefix+tag.Name))
@@ -198,7 +198,7 @@ func testProxyWebsocket(proxy connection.OriginProxy) func(t *testing.T) {
198198
errGroup, ctx := errgroup.WithContext(ctx)
199199
errGroup.Go(func() error {
200200
log := zerolog.Nop()
201-
err = proxy.ProxyHTTP(responseWriter, tracing.NewTracedHTTPRequest(req, &log), true)
201+
err = proxy.ProxyHTTP(responseWriter, tracing.NewTracedHTTPRequest(req, 0, &log), true)
202202
require.NoError(t, err)
203203

204204
require.Equal(t, http.StatusSwitchingProtocols, responseWriter.Code)
@@ -260,7 +260,7 @@ func testProxySSE(proxy connection.OriginProxy) func(t *testing.T) {
260260
go func() {
261261
defer wg.Done()
262262
log := zerolog.Nop()
263-
err = proxy.ProxyHTTP(responseWriter, tracing.NewTracedHTTPRequest(req, &log), false)
263+
err = proxy.ProxyHTTP(responseWriter, tracing.NewTracedHTTPRequest(req, 0, &log), false)
264264
require.Equal(t, err.Error(), "context canceled")
265265

266266
require.Equal(t, http.StatusOK, responseWriter.Code)
@@ -367,7 +367,7 @@ func runIngressTestScenarios(t *testing.T, unvalidatedIngress []config.Unvalidat
367367
req, err := http.NewRequest(http.MethodGet, test.url, nil)
368368
require.NoError(t, err)
369369

370-
err = proxy.ProxyHTTP(responseWriter, tracing.NewTracedHTTPRequest(req, &log), false)
370+
err = proxy.ProxyHTTP(responseWriter, tracing.NewTracedHTTPRequest(req, 0, &log), false)
371371
require.NoError(t, err)
372372

373373
assert.Equal(t, test.expectedStatus, responseWriter.Code)
@@ -414,7 +414,7 @@ func TestProxyError(t *testing.T) {
414414
req, err := http.NewRequest(http.MethodGet, "http://127.0.0.1", nil)
415415
assert.NoError(t, err)
416416

417-
assert.Error(t, proxy.ProxyHTTP(responseWriter, tracing.NewTracedHTTPRequest(req, &log), false))
417+
assert.Error(t, proxy.ProxyHTTP(responseWriter, tracing.NewTracedHTTPRequest(req, 0, &log), false))
418418
}
419419

420420
type replayer struct {
@@ -695,7 +695,7 @@ func TestConnections(t *testing.T) {
695695
err = proxy.ProxyTCP(ctx, rwa, &connection.TCPRequest{Dest: dest})
696696
} else {
697697
log := zerolog.Nop()
698-
err = proxy.ProxyHTTP(respWriter, tracing.NewTracedHTTPRequest(req, &log), test.args.connectionType == connection.TypeWebsocket)
698+
err = proxy.ProxyHTTP(respWriter, tracing.NewTracedHTTPRequest(req, 0, &log), test.args.connectionType == connection.TypeWebsocket)
699699
}
700700

701701
cancel()

‎tracing/tracing.go‎

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -73,15 +73,16 @@ func Init(version string) {
7373
type TracedHTTPRequest struct {
7474
*http.Request
7575
*cfdTracer
76+
ConnIndex uint8 // The connection index used to proxy the request
7677
}
7778

7879
// NewTracedHTTPRequest creates a new tracer for the current HTTP request context.
79-
func NewTracedHTTPRequest(req *http.Request, log *zerolog.Logger) *TracedHTTPRequest {
80+
func NewTracedHTTPRequest(req *http.Request, connIndex uint8, log *zerolog.Logger) *TracedHTTPRequest {
8081
ctx, exists := extractTrace(req)
8182
if !exists {
82-
return &TracedHTTPRequest{req, &cfdTracer{trace.NewNoopTracerProvider(), &NoopOtlpClient{}, log}}
83+
return &TracedHTTPRequest{req, &cfdTracer{trace.NewNoopTracerProvider(), &NoopOtlpClient{}, log}, connIndex}
8384
}
84-
return &TracedHTTPRequest{req.WithContext(ctx), newCfdTracer(ctx, log)}
85+
return &TracedHTTPRequest{req.WithContext(ctx), newCfdTracer(ctx, log), connIndex}
8586
}
8687

8788
func (tr *TracedHTTPRequest) ToTracedContext() *TracedContext {

‎tracing/tracing_test.go‎

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -17,7 +17,7 @@ func TestNewCfTracer(t *testing.T) {
1717
log := zerolog.Nop()
1818
req := httptest.NewRequest("GET", "http://localhost", nil)
1919
req.Header.Add(TracerContextName, "14cb070dde8e51fc5ae8514e69ba42ca:b38f1bf5eae406f3:0:1")
20-
tr := NewTracedHTTPRequest(req, &log)
20+
tr := NewTracedHTTPRequest(req, 0, &log)
2121
assert.NotNil(t, tr)
2222
assert.IsType(t, tracesdk.NewTracerProvider(), tr.TracerProvider)
2323
assert.IsType(t, &InMemoryOtlpClient{}, tr.exporter)
@@ -28,7 +28,7 @@ func TestNewCfTracerMultiple(t *testing.T) {
2828
req := httptest.NewRequest("GET", "http://localhost", nil)
2929
req.Header.Add(TracerContextName, "1241ce3ecdefc68854e8514e69ba42ca:b38f1bf5eae406f3:0:1")
3030
req.Header.Add(TracerContextName, "14cb070dde8e51fc5ae8514e69ba42ca:b38f1bf5eae406f3:0:1")
31-
tr := NewTracedHTTPRequest(req, &log)
31+
tr := NewTracedHTTPRequest(req, 0, &log)
3232
assert.NotNil(t, tr)
3333
assert.IsType(t, tracesdk.NewTracerProvider(), tr.TracerProvider)
3434
assert.IsType(t, &InMemoryOtlpClient{}, tr.exporter)
@@ -38,7 +38,7 @@ func TestNewCfTracerNilHeader(t *testing.T) {
3838
log := zerolog.Nop()
3939
req := httptest.NewRequest("GET", "http://localhost", nil)
4040
req.Header[http.CanonicalHeaderKey(TracerContextName)] = nil
41-
tr := NewTracedHTTPRequest(req, &log)
41+
tr := NewTracedHTTPRequest(req, 0, &log)
4242
assert.NotNil(t, tr)
4343
assert.IsType(t, trace.NewNoopTracerProvider(), tr.TracerProvider)
4444
assert.IsType(t, &NoopOtlpClient{}, tr.exporter)
@@ -49,7 +49,7 @@ func TestNewCfTracerInvalidHeaders(t *testing.T) {
4949
req := httptest.NewRequest("GET", "http://localhost", nil)
5050
for _, test := range [][]string{nil, {""}} {
5151
req.Header[http.CanonicalHeaderKey(TracerContextName)] = test
52-
tr := NewTracedHTTPRequest(req, &log)
52+
tr := NewTracedHTTPRequest(req, 0, &log)
5353
assert.NotNil(t, tr)
5454
assert.IsType(t, trace.NewNoopTracerProvider(), tr.TracerProvider)
5555
assert.IsType(t, &NoopOtlpClient{}, tr.exporter)
@@ -60,7 +60,7 @@ func TestAddingSpansWithNilMap(t *testing.T) {
6060
log := zerolog.Nop()
6161
req := httptest.NewRequest("GET", "http://localhost", nil)
6262
req.Header.Add(TracerContextName, "14cb070dde8e51fc5ae8514e69ba42ca:b38f1bf5eae406f3:0:1")
63-
tr := NewTracedHTTPRequest(req, &log)
63+
tr := NewTracedHTTPRequest(req, 0, &log)
6464

6565
exporter := tr.exporter.(*InMemoryOtlpClient)
6666

0 commit comments

Comments
 (0)