Merge 18cc6dd into b27dea7

uber · Apr 10, 2023 · 85fb069 · 85fb069
2 parents b27dea7 + 18cc6dd
commit 85fb069
Show file tree

Hide file tree

Showing 2 changed files with 22 additions and 1 deletion.
diff --git a/runtime/tchannel_client.go b/runtime/tchannel_client.go
@@ -22,13 +22,15 @@ package zanzibar
 
 import (
 	"context"
+	"fmt"
 	"strings"
 	"time"
 
 	"github.com/pkg/errors"
 	"github.com/uber-go/tally"
 	"github.com/uber/tchannel-go"
 	"github.com/uber/zanzibar/runtime/ruleengine"
+	"go.uber.org/zap"
 	netContext "golang.org/x/net/context"
 )
 
@@ -191,6 +193,7 @@ func (c *TChannelClient) call(
 	}()
 	call.start()
 
+	ctx = call.contextLogger.WarnZ(ctx, "Tchannel call started")
 	reqUUID := RequestUUIDFromCtx(ctx)
 	if reqUUID != "" {
 		if reqHeaders == nil {
@@ -238,24 +241,36 @@ func (c *TChannelClient) call(
 	ctx, cancel := ctxBuilder.Build()
 	defer cancel()
 
+	deadline, ok := ctx.Deadline()
+	if ok {
+		ctx = call.contextLogger.WarnZ(ctx, "ctxBuilder.Build", zap.Time("tchannel-client-deadline", deadline))
+	}
+
 	err = c.ch.RunWithRetry(ctx, func(ctx netContext.Context, rs *tchannel.RequestState) (cerr error) {
 		call.resHeaders = map[string]string{}
 		call.success = false
 
 		sc, ctx := c.getDynamicChannelWithFallback(reqHeaders, c.sc, ctx)
+		ctx = call.contextLogger.Warn(ctx, fmt.Sprintf("Initiating tchannel call with attempt : %d", rs.Attempt))
 		call.call, cerr = sc.BeginCall(ctx, call.serviceMethod, &tchannel.CallOptions{
 			Format:          tchannel.Thrift,
 			ShardKey:        GetShardKeyFromCtx(ctx),
 			RequestState:    rs,
 			RoutingDelegate: GetRoutingDelegateFromCtx(ctx),
 		})
+		if call.call == nil && cerr == nil {
+			ctx = call.contextLogger.Warn(ctx, "Could not make tchannel call")
+		}
 		if cerr != nil {
 			return errors.Wrapf(
 				err, "Could not begin outbound %s.%s (%s %s) request",
 				call.client.ClientID, call.methodName, call.client.serviceName, call.serviceMethod,
 			)
 		}
 
+		if call.call != nil && call.call.Response() != nil {
+			ctx = call.contextLogger.Warn(ctx, fmt.Sprintf("outbound call response format : %s", call.call.Response().Format().String()))
+		}
 		// trace request
 		reqHeaders = tchannel.InjectOutboundSpan(call.call.Response(), reqHeaders)
 

diff --git a/runtime/tchannel_outbound_call.go b/runtime/tchannel_outbound_call.go
@@ -57,6 +57,8 @@ func (c *tchannelOutboundCall) start() {
 func (c *tchannelOutboundCall) finish(ctx context.Context, err error) {
 	c.finishTime = time.Now()
 
+	ctx = c.contextLogger.InfoZ(ctx, "Finishing tchannel call")
+
 	// emit metrics
 	if err != nil {
 		errCause := tchannel.GetSystemErrorCode(errors.Cause(err))
@@ -76,7 +78,11 @@ func (c *tchannelOutboundCall) finish(ctx context.Context, err error) {
 	// write logs
 	fields := c.logFields(ctx)
 	if err == nil {
-		c.contextLogger.Debug(ctx, "Finished an outgoing client TChannel request", fields...)
+		if c.success {
+			c.contextLogger.Debug(ctx, "Finished an outgoing client TChannel request", fields...)
+		} else {
+			c.contextLogger.Warn(ctx, "Unsuccessful outgoing client TChannel request", fields...)
+		}
 	} else {
 		fields = append(fields, zap.Error(err))
 		c.contextLogger.Warn(ctx, "Failed to send outgoing client TChannel request", fields...)