Merge pull request #608 from uber/log_filtering_framework_client

Log filtering framework client. This adds a feature to filter unnecessary/sensitive logs from the client.

codegen/templates/tchannel_client.tmpl

@@ -114,6 +114,7 @@ func {{$exportName}}(deps *module.Dependencies) Client {
 		deps.Default.Channel,
 		deps.Default.Logger,
 		deps.Default.ContextMetrics,
+		deps.Default.ContextExtractor,
 		&zanzibar.TChannelClientOption{
 			ServiceName:          serviceName,
 			ClientID:             "{{$clientID}}",

codegen/templates/tchannel_endpoint.tmpl

@@ -250,6 +250,7 @@ func (h *{{$handlerName}}) redirectToDeputy(
 		h.Deps.Default.Channel,
 		h.Deps.Default.Logger,
 		h.Deps.Default.ContextMetrics,
+		h.Deps.Default.ContextExtractor,
 		&zanzibar.TChannelClientOption{
 			ServiceName:       serviceName,
 			ClientID:           "{{$clientID}}",

examples/example-gateway/app.go

@@ -21,6 +21,8 @@
 package app
 
 import (
+	"net/textproto"
+
 	"go.uber.org/zap"
 
 	"context"
@@ -62,14 +64,12 @@ func getRequestTags(ctx context.Context) map[string]string {
 func getRequestFields(ctx context.Context) []zap.Field {
 	var fields []zap.Field
 	headers := zanzibar.GetEndpointRequestHeadersFromCtx(ctx)
-	uuid, ok := headers["X-Uuid"]
-	if !ok {
-		uuid = headers["x-uuid"]
-	}
-	fields = append(fields, zap.String("x-uuid", uuid))
-	fields = append(fields, zap.String("regionname", headers["Regionname"]))
-	fields = append(fields, zap.String("device", headers["Device"]))
-	fields = append(fields, zap.String("deviceversion", headers["Deviceversion"]))
 
+	for k, v := range headers {
+		if textproto.CanonicalMIMEHeaderKey("x-token") == textproto.CanonicalMIMEHeaderKey(k) {
+			continue
+		}
+		fields = append(fields, zap.String(k, v))
+	}
 	return fields
 }

runtime/tchannel_client.go

@@ -81,6 +81,7 @@ type TChannelClient struct {
 	timeoutPerAttempt time.Duration
 	routingKey        *string
 	metrics           ContextMetrics
+	contextExtractor  ContextExtractor
 
 	requestUUIDHeaderKey string
 }
@@ -90,12 +91,14 @@ func NewTChannelClient(
 	ch *tchannel.Channel,
 	logger *zap.Logger,
 	scope tally.Scope,
+	contextExtractor ContextExtractor,
 	opt *TChannelClientOption,
 ) *TChannelClient {
 	return NewTChannelClientContext(
 		ch,
 		logger,
 		NewContextMetrics(scope),
+		contextExtractor,
 		opt,
 	)
 }
@@ -105,6 +108,7 @@ func NewTChannelClientContext(
 	ch *tchannel.Channel,
 	logger *zap.Logger,
 	metrics ContextMetrics,
+	contextExtractor ContextExtractor,
 	opt *TChannelClientOption,
 ) *TChannelClient {
 	numMethods := len(opt.MethodNames)
@@ -130,6 +134,7 @@ func NewTChannelClientContext(
 		routingKey:        opt.RoutingKey,
 		Loggers:           loggers,
 		metrics:           metrics,
+		contextExtractor:  contextExtractor,
 
 		requestUUIDHeaderKey: opt.RequestUUIDHeaderKey,
 	}
@@ -154,7 +159,6 @@ func (c *TChannelClient) Call(
 		scopeTagsTargetService:  c.serviceName,
 		scopeTagsTargetEndpoint: serviceMethod,
 	}
-
 	ctx = WithScopeTags(ctx, scopeTags)
 	call := &tchannelOutboundCall{
 		client:        c,

runtime/tchannel_client_raw.go

@@ -66,7 +66,7 @@ func NewRawTChannelClient(
 
 	metrics := NewContextMetrics(scope)
 	return &RawTChannelClient{
-		tc:      NewTChannelClientContext(ch, logger, metrics, opt),
+		tc:      NewTChannelClientContext(ch, logger, metrics, nil, opt),
 		logger:  l,
 		metrics: metrics,
 	}

runtime/tchannel_outbound_call.go

@@ -89,15 +89,25 @@ func (c *tchannelOutboundCall) logFields(ctx context.Context) []zapcore.Field {
 		zap.Time("timestamp-finished", c.finishTime),
 	}
 
+	headers := map[string]string{}
 	for k, v := range c.reqHeaders {
-		fields = append(fields, zap.String(
-			fmt.Sprintf("%s-%s", logFieldClientRequestHeaderPrefix, k), v,
-		))
+		s := fmt.Sprintf("%s-%s", logFieldClientRequestHeaderPrefix, k)
+		headers[s] = v
 	}
+
 	for k, v := range c.resHeaders {
-		fields = append(fields, zap.String(
-			fmt.Sprintf("%s-%s", logFieldClientResponseHeaderPrefix, k), v,
-		))
+		s := fmt.Sprintf("%s-%s", logFieldClientResponseHeaderPrefix, k)
+		headers[s] = v
+	}
+
+	// If an extractor function is provided, use it, else copy all the headers
+	if c.client != nil && c.client.contextExtractor != nil {
+		ctx = WithEndpointRequestHeadersField(ctx, headers)
+		fields = append(fields, c.client.contextExtractor.ExtractLogFields(ctx)...)
+	} else {
+		for k, v := range headers {
+			fields = append(fields, zap.String(k, v))
+		}
 	}
 
 	fields = append(fields, GetLogFieldsFromCtx(ctx)...)

test/endpoints/bar/bar_metrics_test.go

@@ -241,10 +241,13 @@ func TestCallMetrics(t *testing.T) {
 		"service":         "example-gateway",
 		"endpointID":      "bar",
 		"endpointHandler": "normal",
-		"x-uuid":          "uuid",
-		"regionname":      "san_francisco",
-		"device":          "ios",
-		"deviceversion":   "carbon",
+		"X-Uuid":          "uuid",
+		"Regionname":      "san_francisco",
+		"Device":          "ios",
+		"Deviceversion":   "carbon",
+		"Content-Length":  "128",
+		"User-Agent":      "Go-http-client/1.1",
+		"Accept-Encoding": "gzip",
 	}
 	for actualKey, actualValue := range logMsg {
 		assert.Equal(t, expectedValues[actualKey], actualValue, "unexpected field %q", actualKey)

test/endpoints/tchannel/baz/baz_simpleservice_method_call_test.go

@@ -136,9 +136,9 @@ func TestCallTChannelSuccessfulRequestOKResponse(t *testing.T) {
 		"x-uuid":               "uuid",
 		"calling-service":      "test-gateway",
 		"zone":                 "unknown",
-		"regionname":           "sf",
-		"device":               "ios",
-		"deviceversion":        "1.0",
+		"Device":               "ios",
+		"Regionname":           "sf",
+		"Deviceversion":        "1.0",
 
 		"Res-Header-some-res-header": "something",
 	}
@@ -178,9 +178,9 @@ func TestCallTChannelSuccessfulRequestOKResponse(t *testing.T) {
 		"endpointThriftMethod": "SimpleService::Call",
 		"endpointHandler":      "call",
 		"x-uuid":               "uuid",
-		"deviceversion":        "1.0",
-		"device":               "ios",
-		"regionname":           "sf",
+		"Deviceversion":        "1.0",
+		"Device":               "ios",
+		"Regionname":           "sf",
 
 		// client specific logs
 		"clientID":                          "baz",

test/lib/bench_gateway/bench_gateway.go

@@ -162,6 +162,7 @@ func CreateGateway(
 		gateway.Channel,
 		gateway.Logger,
 		gateway.RootScope,
+		gateway.ContextExtractor,
 		&zanzibar.TChannelClientOption{
 			ServiceName:       gateway.ServiceName,
 			MethodNames:       opts.TChannelClientMethods,

test/lib/test_gateway/test_gateway.go

@@ -194,18 +194,6 @@ func CreateGateway(
 		timeoutPerAttempt = time.Duration(t.(int)) * time.Millisecond
 	}
 
-	tchannelClient := zanzibar.NewTChannelClientContext(
-		channel,
-		zap.NewNop(),
-		zanzibar.NewContextMetrics(tally.NoopScope),
-		&zanzibar.TChannelClientOption{
-			ServiceName:       serviceName,
-			MethodNames:       opts.TChannelClientMethods,
-			Timeout:           timeout,
-			TimeoutPerAttempt: timeoutPerAttempt,
-		},
-	)
-
 	scopeExtractor := func(ctx context.Context) map[string]string {
 		tags := map[string]string{}
 		headers := zanzibar.GetEndpointRequestHeadersFromCtx(ctx)
@@ -216,10 +204,33 @@ func CreateGateway(
 		return tags
 	}
 
+	logFieldsExtractors := func(ctx context.Context) []zap.Field {
+		reqHeaders := zanzibar.GetEndpointRequestHeadersFromCtx(ctx)
+		fields := make([]zap.Field, 0, len(reqHeaders))
+		for k, v := range reqHeaders {
+			fields = append(fields, zap.String(k, v))
+		}
+		return fields
+	}
+
 	extractors := &zanzibar.ContextExtractors{
 		ScopeTagsExtractors: []zanzibar.ContextScopeTagsExtractor{scopeExtractor},
+		LogFieldsExtractors: []zanzibar.ContextLogFieldsExtractor{logFieldsExtractors},
 	}
 
+	tchannelClient := zanzibar.NewTChannelClientContext(
+		channel,
+		zap.NewNop(),
+		zanzibar.NewContextMetrics(tally.NoopScope),
+		extractors,
+		&zanzibar.TChannelClientOption{
+			ServiceName:       serviceName,
+			MethodNames:       opts.TChannelClientMethods,
+			Timeout:           timeout,
+			TimeoutPerAttempt: timeoutPerAttempt,
+		},
+	)
+
 	testGateway := &ChildProcessGateway{
 		channel:     channel,
 		serviceName: serviceName,