mirror of
https://github.com/temporalio/temporal.git
synced 2026-08-30 18:41:49 -07:00
Tag HSM outbound Nexus call failure logs (#11662)
## What changed The HSM Nexus executor logged outbound call failure logs were missing tags. ## Why `chasm/lib/nexusoperation` already logs exactly these fields via `invocationTraceContext.tags()`, --------- Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
This commit is contained in:
@@ -270,6 +270,19 @@ func (e taskExecutor) executeInvocationTask(ctx context.Context, env hsm.Environ
|
||||
Links: []nexus.Link{args.nexusLink},
|
||||
}
|
||||
|
||||
traceCtx := invocationTraceContext{
|
||||
operationTag: "StartOperation",
|
||||
namespaceName: ns.Name().String(),
|
||||
targetNamespaceID: endpoint.GetEndpoint().GetSpec().GetTarget().GetWorker().GetNamespaceId(),
|
||||
requestID: args.requestID,
|
||||
operation: args.operation,
|
||||
endpointName: args.endpointName,
|
||||
workflowID: ref.WorkflowKey.WorkflowID,
|
||||
runID: ref.WorkflowKey.RunID,
|
||||
attemptStart: time.Now().UTC(),
|
||||
attempt: task.Attempt,
|
||||
}
|
||||
|
||||
var result *nexusrpc.ClientStartOperationResponse[*commonpb.Payload]
|
||||
var callErr error
|
||||
var startTime time.Time
|
||||
@@ -291,18 +304,8 @@ func (e taskExecutor) executeInvocationTask(ctx context.Context, env hsm.Environ
|
||||
}
|
||||
|
||||
if e.HTTPTraceProvider != nil {
|
||||
traceLogger := log.With(e.Logger,
|
||||
tag.Operation("StartOperation"),
|
||||
tag.WorkflowNamespace(ns.Name().String()),
|
||||
tag.RequestID(args.requestID),
|
||||
tag.NexusOperation(args.operation),
|
||||
tag.Endpoint(args.endpointName),
|
||||
tag.WorkflowID(ref.WorkflowKey.WorkflowID),
|
||||
tag.WorkflowRunID(ref.WorkflowKey.RunID),
|
||||
tag.AttemptStart(time.Now().UTC()),
|
||||
tag.Attempt(task.Attempt),
|
||||
)
|
||||
if trace := e.HTTPTraceProvider.NewTrace(task.Attempt, traceLogger); trace != nil {
|
||||
traceLogger := log.With(e.Logger, traceCtx.tags()...)
|
||||
if trace := e.HTTPTraceProvider.NewTrace(traceCtx.attempt, traceLogger); trace != nil {
|
||||
callCtx = httptrace.WithClientTrace(callCtx, trace)
|
||||
}
|
||||
}
|
||||
@@ -333,13 +336,7 @@ func (e taskExecutor) executeInvocationTask(ctx context.Context, env hsm.Environ
|
||||
chasmnexus.OutboundRequestCounter.With(e.MetricsHandler).Record(1, namespaceTag, destTag, methodTag, outcomeTag, failureSourceTag)
|
||||
chasmnexus.OutboundRequestLatency.With(e.MetricsHandler).Record(time.Since(startTime), namespaceTag, destTag, methodTag, outcomeTag, failureSourceTag)
|
||||
|
||||
if callErr != nil {
|
||||
if failureSource == commonnexus.FailureSourceWorker || errors.As(callErr, new(*operationTimeoutBelowMinError)) {
|
||||
e.Logger.Debug("Nexus StartOperation request failed", tag.Error(callErr))
|
||||
} else {
|
||||
e.Logger.Error("Nexus StartOperation request failed", tag.Error(callErr))
|
||||
}
|
||||
}
|
||||
e.logCallFailure(traceCtx, callErr, failureSource)
|
||||
|
||||
err = e.saveResult(ctx, env, ref, result, callErr)
|
||||
|
||||
@@ -734,6 +731,19 @@ func (e taskExecutor) executeCancelationTask(ctx context.Context, env hsm.Enviro
|
||||
// Set this value on the parent context so that our custom HTTP caller can mutate it since we cannot access response headers directly.
|
||||
callCtx = context.WithValue(callCtx, commonnexus.FailureSourceContextKey, &atomic.Value{})
|
||||
|
||||
traceCtx := invocationTraceContext{
|
||||
operationTag: "CancelOperation",
|
||||
namespaceName: ns.Name().String(),
|
||||
targetNamespaceID: endpoint.GetEndpoint().GetSpec().GetTarget().GetWorker().GetNamespaceId(),
|
||||
requestID: args.requestID,
|
||||
operation: args.operation,
|
||||
endpointName: args.endpointName,
|
||||
workflowID: ref.WorkflowKey.WorkflowID,
|
||||
runID: ref.WorkflowKey.RunID,
|
||||
attemptStart: time.Now().UTC(),
|
||||
attempt: task.Attempt,
|
||||
}
|
||||
|
||||
var callErr error
|
||||
var startTime time.Time
|
||||
if callTimeout < e.Config.MinRequestTimeout(ns.Name().String()) {
|
||||
@@ -758,18 +768,8 @@ func (e taskExecutor) executeCancelationTask(ctx context.Context, env hsm.Enviro
|
||||
}
|
||||
|
||||
if e.HTTPTraceProvider != nil {
|
||||
traceLogger := log.With(e.Logger,
|
||||
tag.Operation("CancelOperation"),
|
||||
tag.WorkflowNamespace(ns.Name().String()),
|
||||
tag.RequestID(args.requestID),
|
||||
tag.NexusOperation(args.operation),
|
||||
tag.Endpoint(args.endpointName),
|
||||
tag.WorkflowID(ref.WorkflowKey.WorkflowID),
|
||||
tag.WorkflowRunID(ref.WorkflowKey.RunID),
|
||||
tag.AttemptStart(time.Now().UTC()),
|
||||
tag.Attempt(task.Attempt),
|
||||
)
|
||||
if trace := e.HTTPTraceProvider.NewTrace(task.Attempt, traceLogger); trace != nil {
|
||||
traceLogger := log.With(e.Logger, traceCtx.tags()...)
|
||||
if trace := e.HTTPTraceProvider.NewTrace(traceCtx.attempt, traceLogger); trace != nil {
|
||||
callCtx = httptrace.WithClientTrace(callCtx, trace)
|
||||
}
|
||||
}
|
||||
@@ -791,13 +791,7 @@ func (e taskExecutor) executeCancelationTask(ctx context.Context, env hsm.Enviro
|
||||
chasmnexus.OutboundRequestCounter.With(e.MetricsHandler).Record(1, namespaceTag, destTag, methodTag, statusCodeTag, failureSourceTag)
|
||||
chasmnexus.OutboundRequestLatency.With(e.MetricsHandler).Record(time.Since(startTime), namespaceTag, destTag, methodTag, statusCodeTag, failureSourceTag)
|
||||
|
||||
if callErr != nil {
|
||||
if failureSource == commonnexus.FailureSourceWorker || errors.As(callErr, new(*operationTimeoutBelowMinError)) {
|
||||
e.Logger.Debug("Nexus CancelOperation request failed", tag.Error(callErr))
|
||||
} else {
|
||||
e.Logger.Error("Nexus CancelOperation request failed", tag.Error(callErr))
|
||||
}
|
||||
}
|
||||
e.logCallFailure(traceCtx, callErr, failureSource)
|
||||
|
||||
err = e.saveCancelationResult(ctx, env, ref, callErr, args.scheduledEventID)
|
||||
|
||||
@@ -1025,6 +1019,51 @@ func cancelCallOutcomeTag(callCtx context.Context, callErr error) string {
|
||||
return "successful"
|
||||
}
|
||||
|
||||
// invocationTraceContext captures per-call contextual information used for HTTP tracing and failure logging.
|
||||
type invocationTraceContext struct {
|
||||
operationTag string // "StartOperation" or "CancelOperation"
|
||||
namespaceName string // source (caller) namespace
|
||||
targetNamespaceID string
|
||||
requestID string
|
||||
operation string
|
||||
endpointName string
|
||||
workflowID string
|
||||
runID string
|
||||
attemptStart time.Time
|
||||
attempt int32
|
||||
}
|
||||
|
||||
// tags returns the structured log tags describing the call.
|
||||
func (c invocationTraceContext) tags() []tag.Tag {
|
||||
return []tag.Tag{
|
||||
tag.Operation(c.operationTag),
|
||||
tag.WorkflowNamespace(c.namespaceName),
|
||||
tag.NexusEndpointTargetNamespaceID(c.targetNamespaceID),
|
||||
tag.RequestID(c.requestID),
|
||||
tag.NexusOperation(c.operation),
|
||||
tag.Endpoint(c.endpointName),
|
||||
tag.WorkflowID(c.workflowID),
|
||||
tag.WorkflowRunID(c.runID),
|
||||
tag.AttemptStart(c.attemptStart),
|
||||
tag.Attempt(c.attempt),
|
||||
}
|
||||
}
|
||||
|
||||
// logCallFailure logs a failed outbound Nexus call.
|
||||
func (e taskExecutor) logCallFailure(traceCtx invocationTraceContext, callErr error, failureSource string) {
|
||||
if callErr == nil {
|
||||
return
|
||||
}
|
||||
tags := append(traceCtx.tags(), tag.Error(callErr))
|
||||
msg := fmt.Sprintf("Nexus %s request failed", traceCtx.operationTag)
|
||||
_, isTimeoutBelowMin := errors.AsType[*operationTimeoutBelowMinError](callErr)
|
||||
if failureSource == commonnexus.FailureSourceWorker || isTimeoutBelowMin {
|
||||
e.Logger.Debug(msg, tags...)
|
||||
} else {
|
||||
e.Logger.Error(msg, tags...)
|
||||
}
|
||||
}
|
||||
|
||||
func isDestinationDown(err error) bool {
|
||||
var serviceErr serviceerror.ServiceError
|
||||
// For the system endpoint, we don't even consider the destination down since it's internal.
|
||||
|
||||
Reference in New Issue
Block a user