From bfd595de37a09c1805b1f88d605b595a293e1d1d Mon Sep 17 00:00:00 2001 From: Yushan Lin Date: Tue, 30 Jun 2026 15:29:29 -0700 Subject: [PATCH 1/9] Remove more error logs and surface/wrap errors --- MODULE.bazel | 1 + controller/getchangedtargets.go | 4 ---- controller/gettargetgraph.go | 3 --- go.mod | 2 +- orchestrator/native_orchestrator.go | 8 ++++---- 5 files changed, 6 insertions(+), 12 deletions(-) diff --git a/MODULE.bazel b/MODULE.bazel index aa4f745..6e1f062 100644 --- a/MODULE.bazel +++ b/MODULE.bazel @@ -40,6 +40,7 @@ use_repo( "org_uber_go_fx", "org_uber_go_goleak", "org_uber_go_mock", + "org_uber_go_multierr", "org_uber_go_yarpc", "org_uber_go_zap", ) diff --git a/controller/getchangedtargets.go b/controller/getchangedtargets.go index 1014984..e883104 100644 --- a/controller/getchangedtargets.go +++ b/controller/getchangedtargets.go @@ -82,7 +82,6 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str cacheStart := time.Now() treehash1, treehash2, err := readTreehashParallel(ctx, c.storage, request.GetFirstRevision(), request.GetSecondRevision()) if err != nil { - logger.Error("GetChangedTargets: Failed to read revision treehash", zap.Error(err)) return common.WithReason(failureReasonTreehashRead, common.ErrorTypeInfra, err) } if treehash1 != "" && treehash2 != "" { @@ -126,7 +125,6 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str scope.Counter("changed_targets_cache_hit").Inc(1) scope.Timer("cache_read_duration").Record(cacheReadDuration) if sendErr := sendTrimmedChangedTargets(stream, cached, maxDist, request.GetOutputConfig()); sendErr != nil { - logger.Error("GetChangedTargets: Failed to send cached response", zap.Error(sendErr)) return common.WithReason(failureReasonSend, common.ErrorTypeInfra, fmt.Errorf("failed to send cached response: %w", sendErr)) } totalDuration := time.Since(start) @@ -263,7 +261,6 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str if ctx.Err() != nil { return common.WithReason(common.FailureReasonCancelled, common.ErrorTypeUser, ctx.Err()) } - logger.Error("GetChangedTargets: Failed to compare target graphs", zap.Error(err)) return common.WithReason(failureReasonCompare, common.ErrorTypeInfra, fmt.Errorf("failed to compare target graphs: %w", err)) } compareDuration := time.Since(compareStart) @@ -306,7 +303,6 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str sendStart := time.Now() if err := sendTrimmedChangedTargets(stream, changedTargetsResponses, maxDist, request.GetOutputConfig()); err != nil { - logger.Error("GetChangedTargets: Failed to send response", zap.Error(err)) return common.WithReason(failureReasonSend, common.ErrorTypeInfra, fmt.Errorf("failed to send response: %w", err)) } sendDuration := time.Since(sendStart) diff --git a/controller/gettargetgraph.go b/controller/gettargetgraph.go index fa0450e..e0b0f35 100644 --- a/controller/gettargetgraph.go +++ b/controller/gettargetgraph.go @@ -107,14 +107,12 @@ func (c *controller) getGraph(ctx context.Context, buildDescription *pb.BuildDes logger.Debug("getGraph: treehash not found", zap.Error(err)) } else { // Other errors (network, infra issues) should be retried - logger.Error("getGraph: Storage error", zap.Error(err)) return nil, err } } else { defer treehashResponse.ReadCloser.Close() treehashBytes, err := io.ReadAll(treehashResponse.ReadCloser) if err != nil { - logger.Error("getGraph: Error reading treehash", zap.Error(err)) return nil, err } logger.Info("getGraph: treehash found") @@ -127,7 +125,6 @@ func (c *controller) getGraph(ctx context.Context, buildDescription *pb.BuildDes return nil, common.WithReason(common.FailureReasonCancelled, common.ErrorTypeUser, ctx.Err()) } if !storage.IsNotFound(err) { - logger.Error("getGraph: Error reading graph from Storage", zap.Error(err)) return nil, common.WithReason(failureReasonGraphFetch, common.ErrorTypeInfra, err) } logger.Warn("getGraph: graph not found at treehash path", zap.Error(err)) diff --git a/go.mod b/go.mod index 2133477..14eddfd 100644 --- a/go.mod +++ b/go.mod @@ -14,6 +14,7 @@ require ( go.uber.org/fx v1.24.0 go.uber.org/goleak v1.3.0 go.uber.org/mock v0.6.0 + go.uber.org/multierr v1.11.0 go.uber.org/yarpc v1.81.0 go.uber.org/zap v1.27.0 golang.org/x/sync v0.16.0 @@ -40,7 +41,6 @@ require ( github.com/uber/tchannel-go v1.34.4 // indirect go.uber.org/atomic v1.11.0 // indirect go.uber.org/dig v1.19.0 // indirect - go.uber.org/multierr v1.11.0 // indirect go.uber.org/net/metrics v1.4.0 // indirect go.uber.org/thriftrw v1.32.0 // indirect golang.org/x/exp/typeparams v0.0.0-20221208152030-732eee02a75a // indirect diff --git a/orchestrator/native_orchestrator.go b/orchestrator/native_orchestrator.go index 58d7ac5..81cef20 100644 --- a/orchestrator/native_orchestrator.go +++ b/orchestrator/native_orchestrator.go @@ -25,6 +25,7 @@ import ( "github.com/uber-go/tally" "github.com/uber/tango/config" + "go.uber.org/multierr" "github.com/uber/tango/core/bazel" "github.com/uber/tango/core/common" "github.com/uber/tango/core/git" @@ -128,11 +129,10 @@ func (b *nativeOrchestrator) GetTargetGraph(ctx context.Context, param GetTarget return nil, fmt.Errorf("lease workspace: %w", err) } defer func() { - err := ws.Release() - if err != nil { - // clean up the workspace if release fails. + if releaseErr := ws.Release(); releaseErr != nil { + retErr = multierr.Append(retErr, fmt.Errorf("release workspace: %w", releaseErr)) if removeErr := os.RemoveAll(ws.Path()); removeErr != nil { - logger.Errorw("GetTargetGraph: Failed to remove workspace", zap.Error(removeErr)) + retErr = multierr.Append(retErr, fmt.Errorf("remove workspace: %w", removeErr)) } } }() From cf1588ae49fcd56eb09636a07d0c15b563e57260 Mon Sep 17 00:00:00 2001 From: Yushan Lin Date: Tue, 30 Jun 2026 15:33:52 -0700 Subject: [PATCH 2/9] Update --- controller/getchangedtargets.go | 18 ++++++++---------- 1 file changed, 8 insertions(+), 10 deletions(-) diff --git a/controller/getchangedtargets.go b/controller/getchangedtargets.go index e883104..da314fe 100644 --- a/controller/getchangedtargets.go +++ b/controller/getchangedtargets.go @@ -52,7 +52,7 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str } }() if err := validateGetChangedTargetsRequest(request); err != nil { - return common.WithReason(common.FailureReasonValidation, common.ErrorTypeUser, err) + return fmt.Errorf("validate request: %w", err) } scope = scope.Tagged(map[string]string{"repo": common.ToShortRemote(request.GetFirstRevision().GetRemote())}) ctx, cancelLink := c.linkRequestCtx(stream.Context()) @@ -82,7 +82,7 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str cacheStart := time.Now() treehash1, treehash2, err := readTreehashParallel(ctx, c.storage, request.GetFirstRevision(), request.GetSecondRevision()) if err != nil { - return common.WithReason(failureReasonTreehashRead, common.ErrorTypeInfra, err) + return fmt.Errorf("read revision treehash: %w", err) } if treehash1 != "" && treehash2 != "" { cacheKey := common.GetComparedTargetsCachePath(request.GetFirstRevision().GetRemote(), treehash1, treehash2, request.GetRequestOptions()) @@ -98,8 +98,7 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str for { if err := ctx.Err(); err != nil { cachedReader.Close() - // Client gave up while we were draining the cache. Surface as a user-cancelled error. - return common.WithReason(common.FailureReasonCancelled, common.ErrorTypeUser, err) + return err } var resp *pb.GetChangedTargetsResponse resp, readErr = cachedReader.Read() @@ -125,7 +124,7 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str scope.Counter("changed_targets_cache_hit").Inc(1) scope.Timer("cache_read_duration").Record(cacheReadDuration) if sendErr := sendTrimmedChangedTargets(stream, cached, maxDist, request.GetOutputConfig()); sendErr != nil { - return common.WithReason(failureReasonSend, common.ErrorTypeInfra, fmt.Errorf("failed to send cached response: %w", sendErr)) + return fmt.Errorf("failed to send cached response: %w", sendErr) } totalDuration := time.Since(start) logger.Info("GetChangedTargets: Successfully streamed from cache", @@ -227,8 +226,7 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str scope.Timer("graph_fetch_duration").Record(graphFetchDuration) if ctx.Err() != nil { - // If the context was cancelled by the upstream, just return the original error without additional augmentation - return common.WithReason(common.FailureReasonCancelled, common.ErrorTypeUser, ctx.Err()) + return ctx.Err() } // Process errors, only aggregating the ones that are original ones and not a result of the other job being cancelled @@ -259,9 +257,9 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str secondGraph = nil if err != nil { if ctx.Err() != nil { - return common.WithReason(common.FailureReasonCancelled, common.ErrorTypeUser, ctx.Err()) + return ctx.Err() } - return common.WithReason(failureReasonCompare, common.ErrorTypeInfra, fmt.Errorf("failed to compare target graphs: %w", err)) + return fmt.Errorf("failed to compare target graphs: %w", err) } compareDuration := time.Since(compareStart) logger.Info("GetChangedTargets: Target graphs compared", @@ -303,7 +301,7 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str sendStart := time.Now() if err := sendTrimmedChangedTargets(stream, changedTargetsResponses, maxDist, request.GetOutputConfig()); err != nil { - return common.WithReason(failureReasonSend, common.ErrorTypeInfra, fmt.Errorf("failed to send response: %w", err)) + return fmt.Errorf("failed to send response: %w", err) } sendDuration := time.Since(sendStart) scope.Timer("send_duration").Record(sendDuration) From 02af47f21826bf0920903c23ca9c4608454b9d79 Mon Sep 17 00:00:00 2001 From: Yushan Lin Date: Tue, 30 Jun 2026 15:58:39 -0700 Subject: [PATCH 3/9] Update --- orchestrator/BUILD.bazel | 1 + 1 file changed, 1 insertion(+) diff --git a/orchestrator/BUILD.bazel b/orchestrator/BUILD.bazel index 64ceb5c..aa0102e 100644 --- a/orchestrator/BUILD.bazel +++ b/orchestrator/BUILD.bazel @@ -20,6 +20,7 @@ go_library( "//graphrunner", "//tangopb", "@com_github_uber_go_tally//:tally", + "@org_uber_go_multierr//:multierr", "@org_uber_go_zap//:zap", ], ) From e99daad1c6288eb37d7dfc6da6c177c74df1681c Mon Sep 17 00:00:00 2001 From: Yushan Lin Date: Tue, 30 Jun 2026 16:08:50 -0700 Subject: [PATCH 4/9] Update --- controller/getchangedtargets.go | 46 +++++++++++++++------------- controller/getchangedtargets_test.go | 13 ++------ 2 files changed, 27 insertions(+), 32 deletions(-) diff --git a/controller/getchangedtargets.go b/controller/getchangedtargets.go index da314fe..ea2563e 100644 --- a/controller/getchangedtargets.go +++ b/controller/getchangedtargets.go @@ -88,7 +88,7 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str cacheKey := common.GetComparedTargetsCachePath(request.GetFirstRevision().GetRemote(), treehash1, treehash2, request.GetRequestOptions()) cachedReader, cacheErr := storage.NewChangedTargetsReader(ctx, c.storage, cacheKey) if cacheErr != nil && !storage.IsNotFound(cacheErr) { - logger.Warn("GetChangedTargets: Failed to read from cache, proceeding to compute", zap.Error(cacheErr)) + return fmt.Errorf("failed to read from cache: %w", cacheErr) } else if cachedReader != nil { // Buffer all responses before sending any. A concurrent goroutine write may have // left a partial blob in storage; buffering lets us detect corruption and fall @@ -97,7 +97,9 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str var readErr error for { if err := ctx.Err(); err != nil { - cachedReader.Close() + if closeErr := cachedReader.Close(); closeErr != nil { + return fmt.Errorf("close cached reader: %w (original: %w)", closeErr, err) + } return err } var resp *pb.GetChangedTargetsResponse @@ -111,29 +113,29 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str } cached = append(cached, resp) } - cachedReader.Close() + if closeErr := cachedReader.Close(); closeErr != nil { + return fmt.Errorf("close cached reader: %w", closeErr) + } if readErr != nil { - // Blob is corrupt (likely an incomplete write). Log and fall through to recompute. - logger.Warn("GetChangedTargets: Cached result is incomplete, recomputing", zap.Error(readErr)) - } else { - cacheReadDuration := time.Since(cacheStart) - logger.Info("GetChangedTargets: Cache hit, streaming from storage", - zap.Duration("cache_read_duration", cacheReadDuration), - ) - scope.Counter("changed_targets_cache_hit").Inc(1) - scope.Timer("cache_read_duration").Record(cacheReadDuration) - if sendErr := sendTrimmedChangedTargets(stream, cached, maxDist, request.GetOutputConfig()); sendErr != nil { - return fmt.Errorf("failed to send cached response: %w", sendErr) - } - totalDuration := time.Since(start) - logger.Info("GetChangedTargets: Successfully streamed from cache", - zap.Duration("total_duration", totalDuration), - ) - scope.Timer("total_duration").Record(totalDuration) - scope.Histogram("total_duration.histogram", c.totalDurationBuckets).RecordDuration(totalDuration) - return nil + return fmt.Errorf("read cached response: %w", readErr) + } + cacheReadDuration := time.Since(cacheStart) + logger.Info("GetChangedTargets: Cache hit, streaming from storage", + zap.Duration("cache_read_duration", cacheReadDuration), + ) + scope.Counter("changed_targets_cache_hit").Inc(1) + scope.Timer("cache_read_duration").Record(cacheReadDuration) + if sendErr := sendTrimmedChangedTargets(stream, cached, maxDist, request.GetOutputConfig()); sendErr != nil { + return fmt.Errorf("failed to send cached response: %w", sendErr) } + totalDuration := time.Since(start) + logger.Info("GetChangedTargets: Successfully streamed from cache", + zap.Duration("total_duration", totalDuration), + ) + scope.Timer("total_duration").Record(totalDuration) + scope.Histogram("total_duration.histogram", c.totalDurationBuckets).RecordDuration(totalDuration) + return nil } } } diff --git a/controller/getchangedtargets_test.go b/controller/getchangedtargets_test.go index 1e854fc..e71f98b 100644 --- a/controller/getchangedtargets_test.go +++ b/controller/getchangedtargets_test.go @@ -27,7 +27,6 @@ import ( gogio "github.com/gogo/protobuf/io" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" - "github.com/uber/tango/core/common" "github.com/uber/tango/core/storage" storagemock "github.com/uber/tango/core/storage/storagemock" orchestratormock "github.com/uber/tango/orchestrator/orchestratormock" @@ -158,7 +157,7 @@ func TestGetChangedTargets_ValidationError(t *testing.T) { c := NewController(context.Background(), Params{Logger: zap.NewNop(), Orchestrator: orchestratormock.NewMockOrchestrator(ctrl)}) err := c.GetChangedTargets(nil, stream) - assert.EqualError(t, err, "request cannot be nil") + assert.EqualError(t, err, "validate request: request cannot be nil") } func TestGetChangedTargets_CacheHit(t *testing.T) { @@ -219,10 +218,7 @@ func TestGetChangedTargets_TreehashReadError(t *testing.T) { storagemock := storagemock.NewMockStorage(ctrl) // A non-NotFound storage error on a treehash read must surface as a failed - // request (with failureReasonTreehashRead) rather than be silently treated - // as a cache miss. Both revision treehashes are read in parallel, so two Get - // calls happen; the handler returns the first failure (and drops the - // cancelled sibling's error) before any graph fetch happens. + // request rather than be silently treated as a cache miss. injected := errors.New("storage exploded") storagemock.EXPECT().Get(gomock.Any(), gomock.Any()). Return(storage.DownloadResponse{}, injected).Times(2) @@ -242,10 +238,7 @@ func TestGetChangedTargets_TreehashReadError(t *testing.T) { err := c.GetChangedTargets(request, stream) require.Error(t, err) require.ErrorIs(t, err, injected) - var ce common.ClassifiedError - require.True(t, errors.As(err, &ce), "expected ClassifiedError, got %T", err) - assert.Equal(t, failureReasonTreehashRead, ce.Reason()) - assert.Equal(t, common.ErrorTypeInfra, ce.Type()) + assert.Contains(t, err.Error(), "read revision treehash") } func TestReadTreehash(t *testing.T) { From 07f5a7acb6c57d8470c5ee0e86949f12a3b6ff19 Mon Sep 17 00:00:00 2001 From: Yushan Lin Date: Tue, 30 Jun 2026 16:14:13 -0700 Subject: [PATCH 5/9] Update --- orchestrator/native_orchestrator.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/orchestrator/native_orchestrator.go b/orchestrator/native_orchestrator.go index 81cef20..fda7ea3 100644 --- a/orchestrator/native_orchestrator.go +++ b/orchestrator/native_orchestrator.go @@ -25,7 +25,6 @@ import ( "github.com/uber-go/tally" "github.com/uber/tango/config" - "go.uber.org/multierr" "github.com/uber/tango/core/bazel" "github.com/uber/tango/core/common" "github.com/uber/tango/core/git" @@ -33,6 +32,7 @@ import ( "github.com/uber/tango/core/storage" "github.com/uber/tango/core/workspace" "github.com/uber/tango/graphrunner" + "go.uber.org/multierr" "go.uber.org/zap" ) From 33bc632d8b0a2d79dcd36f5adee3ff3ac22cb52e Mon Sep 17 00:00:00 2001 From: Yushan Lin Date: Tue, 30 Jun 2026 17:23:19 -0700 Subject: [PATCH 6/9] Update logging --- controller/getchangedtargets.go | 30 +++++----------------------- controller/getchangedtargets_test.go | 20 +++++++++---------- controller/gettargetgraph.go | 28 ++++++++------------------ orchestrator/native_orchestrator.go | 8 +------- 4 files changed, 24 insertions(+), 62 deletions(-) diff --git a/controller/getchangedtargets.go b/controller/getchangedtargets.go index ea2563e..59af489 100644 --- a/controller/getchangedtargets.go +++ b/controller/getchangedtargets.go @@ -43,10 +43,12 @@ type job struct { func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, stream pb.TangoServiceGetChangedTargetsYARPCServer) (retErr error) { scope := c.scope.SubScope("get_changed_targets") scope.Counter("calls").Inc(1) + logger := c.logger defer func() { if retErr != nil { scope.Counter("failure").Inc(1) emitFailureMetric(scope, retErr) + logger.Error("GetChangedTargets failed", zap.Error(retErr)) } else { scope.Counter("success").Inc(1) } @@ -58,13 +60,11 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str ctx, cancelLink := c.linkRequestCtx(stream.Context()) defer cancelLink() start := time.Now() - logger := c.logger.With( + logger = c.logger.With( zap.Any("first_revision", request.GetFirstRevision()), zap.Any("second_revision", request.GetSecondRevision()), ) - logger.Info("GetChangedTargets: Processing request") - // Default max_distance to -1 (no filtering) when the client omits OutputConfig // entirely. When OutputConfig is supplied, take max_distance at face value — // see proto/tango.proto OutputConfig.max_distance for the wire-default caveat. @@ -121,18 +121,12 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str return fmt.Errorf("read cached response: %w", readErr) } cacheReadDuration := time.Since(cacheStart) - logger.Info("GetChangedTargets: Cache hit, streaming from storage", - zap.Duration("cache_read_duration", cacheReadDuration), - ) scope.Counter("changed_targets_cache_hit").Inc(1) scope.Timer("cache_read_duration").Record(cacheReadDuration) if sendErr := sendTrimmedChangedTargets(stream, cached, maxDist, request.GetOutputConfig()); sendErr != nil { return fmt.Errorf("failed to send cached response: %w", sendErr) } totalDuration := time.Since(start) - logger.Info("GetChangedTargets: Successfully streamed from cache", - zap.Duration("total_duration", totalDuration), - ) scope.Timer("total_duration").Record(totalDuration) scope.Histogram("total_duration.histogram", c.totalDurationBuckets).RecordDuration(totalDuration) return nil @@ -222,9 +216,6 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str } graphFetchDuration := time.Since(graphFetchStart) - logger.Info("GetChangedTargets: Both graphs fetched", - zap.Duration("graph_fetch_duration", graphFetchDuration), - ) scope.Timer("graph_fetch_duration").Record(graphFetchDuration) if ctx.Err() != nil { @@ -253,7 +244,7 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str jobs[1].graphStreamChunks = nil compareStart := time.Now() - changedTargetsResponses, err := c.compareTargetGraphs(ctx, logger, firstGraph, secondGraph, maxDist) + changedTargetsResponses, err := c.compareTargetGraphs(ctx, firstGraph, secondGraph, maxDist) // Allow GC of raw graph data while the caching goroutine runs. firstGraph = nil secondGraph = nil @@ -264,9 +255,6 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str return fmt.Errorf("failed to compare target graphs: %w", err) } compareDuration := time.Since(compareStart) - logger.Info("GetChangedTargets: Target graphs compared", - zap.Duration("compare_duration", compareDuration), - ) scope.Timer("compare_duration").Record(compareDuration) // Cache the computed result concurrently so it doesn't block the stream send. @@ -309,10 +297,6 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str scope.Timer("send_duration").Record(sendDuration) totalDuration := time.Since(start) - logger.Info("GetChangedTargets: Successfully processed request", - zap.Duration("send_duration", sendDuration), - zap.Duration("total_duration", totalDuration), - ) scope.Timer("total_duration").Record(totalDuration) scope.Histogram("total_duration.histogram", c.totalDurationBuckets).RecordDuration(totalDuration) return nil @@ -327,10 +311,9 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str // targets get their distance from BFS over the reverse-dep graph. // Output IDs are re-mapped into a canonical per-call namespace so the // response metadata only carries the names actually referenced. -func (c *controller) compareTargetGraphs(ctx context.Context, logger *zap.Logger, firstGraph, secondGraph []*pb.GetTargetGraphResponse, maxDist int32) ([]*pb.GetChangedTargetsResponse, error) { +func (c *controller) compareTargetGraphs(ctx context.Context, firstGraph, secondGraph []*pb.GetTargetGraphResponse, maxDist int32) ([]*pb.GetChangedTargetsResponse, error) { start := time.Now() scope := c.scope.SubScope("compare_target_graphs") - logger.Info("compareTargetGraphs: Computing differences between target graphs") // 1) Extract targets and metadata; index by canonical names indexStart := time.Now() @@ -588,9 +571,6 @@ func (c *controller) compareTargetGraphs(ctx context.Context, logger *zap.Logger }) } totalDuration := time.Since(start) - logger.Info("compareTargetGraphs: Done", - zap.Duration("total_duration", totalDuration), - ) scope.Timer("total_duration").Record(totalDuration) return results, nil } diff --git a/controller/getchangedtargets_test.go b/controller/getchangedtargets_test.go index e71f98b..31026a6 100644 --- a/controller/getchangedtargets_test.go +++ b/controller/getchangedtargets_test.go @@ -145,7 +145,7 @@ func TestCompareTargetGraphs(t *testing.T) { }, } - response, err := c.compareTargetGraphs(context.Background(), zap.NewNop(), []*pb.GetTargetGraphResponse{firstGraph}, []*pb.GetTargetGraphResponse{secondGraph}, -1) + response, err := c.compareTargetGraphs(context.Background(),[]*pb.GetTargetGraphResponse{firstGraph}, []*pb.GetTargetGraphResponse{secondGraph}, -1) require.NoError(t, err) require.NotNil(t, response) } @@ -606,7 +606,7 @@ func TestCompareTargetGraphs_NewTarget_CanonicalIDs(t *testing.T) { }, }, } - res, err := c.compareTargetGraphs(context.Background(), zap.NewNop(), first, second, -1) + res, err := c.compareTargetGraphs(context.Background(),first, second, -1) require.NoError(t, err) require.Len(t, res, 2) cs := res[0].GetChangedTargets() @@ -678,7 +678,7 @@ func TestCompareTargetGraphs_SourceFileDirectAndPropagation(t *testing.T) { }, }, } - res, err := c.compareTargetGraphs(context.Background(), zap.NewNop(), first, second, -1) + res, err := c.compareTargetGraphs(context.Background(),first, second, -1) require.NoError(t, err) cs := res[0].GetChangedTargets() require.NotNil(t, cs) @@ -751,7 +751,7 @@ func TestCompareTargetGraphs_ChangedRuleUnreachableFromAnySeed(t *testing.T) { // Hash-only change on a rule with no own-config change and no reachable // seed: under "trust the hasher" semantics, an orphan CHANGED rule with // no upstream explanation becomes a distance-0 seed itself. - res, err := c.compareTargetGraphs(context.Background(), zap.NewNop(), first, second, -1) + res, err := c.compareTargetGraphs(context.Background(),first, second, -1) require.NoError(t, err) cs := res[0].GetChangedTargets() require.NotNil(t, cs) @@ -818,7 +818,7 @@ func TestCompareTargetGraphs_ChangedWhenDependenciesChanged(t *testing.T) { }, }, } - res, err := c.compareTargetGraphs(context.Background(), zap.NewNop(), first, second, -1) + res, err := c.compareTargetGraphs(context.Background(),first, second, -1) require.NoError(t, err) cs := res[0].GetChangedTargets() require.NotNil(t, cs) @@ -900,7 +900,7 @@ func TestCompareTargetGraphs_ChangedWhenAttributesChanged(t *testing.T) { }, }, } - res, err := c.compareTargetGraphs(context.Background(), zap.NewNop(), first, second, -1) + res, err := c.compareTargetGraphs(context.Background(),first, second, -1) require.NoError(t, err) cs := res[0].GetChangedTargets() require.NotNil(t, cs) @@ -982,7 +982,7 @@ func TestCompareTargetGraphs_ChangedWhenNewAttributeAdded(t *testing.T) { }, }, } - res, err := c.compareTargetGraphs(context.Background(), zap.NewNop(), first, second, -1) + res, err := c.compareTargetGraphs(context.Background(),first, second, -1) require.NoError(t, err) cs := res[0].GetChangedTargets() require.NotNil(t, cs) @@ -1322,7 +1322,7 @@ func TestCompareTargetGraphs_HashOnlyChangePropagatesViaBFS(t *testing.T) { }, }, } - res, err := c.compareTargetGraphs(context.Background(), zap.NewNop(), first, second, -1) + res, err := c.compareTargetGraphs(context.Background(),first, second, -1) require.NoError(t, err) cs := res[0].GetChangedTargets() require.NotNil(t, cs) @@ -1404,7 +1404,7 @@ func TestCompareTargetGraphs_SiblingRuleNotPromotedToSeed(t *testing.T) { }, }, } - res, err := c.compareTargetGraphs(context.Background(), zap.NewNop(), first, second, -1) + res, err := c.compareTargetGraphs(context.Background(),first, second, -1) require.NoError(t, err) cs := res[0].GetChangedTargets() require.NotNil(t, cs) @@ -1458,7 +1458,7 @@ func TestCompareTargetGraphs_DeletedTargetEmitted(t *testing.T) { }, }, } - res, err := c.compareTargetGraphs(context.Background(), zap.NewNop(), first, second, -1) + res, err := c.compareTargetGraphs(context.Background(),first, second, -1) require.NoError(t, err) cs := res[0].GetChangedTargets() require.NotNil(t, cs) diff --git a/controller/gettargetgraph.go b/controller/gettargetgraph.go index e0b0f35..e8eb453 100644 --- a/controller/gettargetgraph.go +++ b/controller/gettargetgraph.go @@ -33,20 +33,21 @@ import ( func (c *controller) GetTargetGraph(request *pb.GetTargetGraphRequest, stream pb.TangoServiceGetTargetGraphYARPCServer) (retErr error) { scope := c.scope.SubScope("get_target_graph") scope.Counter("calls").Inc(1) + start := time.Now() + ctx, cancelLink := c.linkRequestCtx(stream.Context()) + defer cancelLink() + logger := c.logger.With( + zap.Any("build_description", request.GetBuildDescription()), + ) defer func() { if retErr != nil { scope.Counter("failure").Inc(1) emitFailureMetric(scope, retErr) + logger.Error("GetTargetGraph failed", zap.Error(retErr)) } else { scope.Counter("success").Inc(1) } }() - start := time.Now() - ctx, cancelLink := c.linkRequestCtx(stream.Context()) - defer cancelLink() - logger := c.logger.With( - zap.Any("build_description", request.GetBuildDescription()), - ) scope = scope.Tagged(map[string]string{"repo": common.ToShortRemote(request.GetBuildDescription().GetRemote())}) graphReader, err := c.getGraph(ctx, request.GetBuildDescription(), request.GetOutputConfig(), request.GetRequestOptions(), request.GetBypassCache()) if err != nil { @@ -64,10 +65,6 @@ func (c *controller) GetTargetGraph(request *pb.GetTargetGraphRequest, stream pb if err == io.EOF { sendDuration := time.Since(sendStart) totalDuration := time.Since(start) - logger.Info("GetTargetGraph: Done streaming", - zap.Duration("send_duration", sendDuration), - zap.Duration("total_duration", totalDuration), - ) scope.Timer("send_duration").Record(sendDuration) scope.Timer("total_duration").Record(totalDuration) return nil @@ -115,7 +112,6 @@ func (c *controller) getGraph(ctx context.Context, buildDescription *pb.BuildDes if err != nil { return nil, err } - logger.Info("getGraph: treehash found") treehashPath := common.GetGraphByTreeHash(buildDescription.GetRemote(), string(treehashBytes), buildDescription.GetStrategy(), requestOptions) // Download the target graph based on treehash. storageStart := time.Now() @@ -129,10 +125,6 @@ func (c *controller) getGraph(ctx context.Context, buildDescription *pb.BuildDes } logger.Warn("getGraph: graph not found at treehash path", zap.Error(err)) } else { - logger.Info("getGraph: loaded graph from storage", - zap.Duration("storage_duration", time.Since(storageStart)), - zap.Duration("total_duration", time.Since(start)), - ) scope := c.scope.SubScope("get_graph") scope.Counter("graph_cache_hit").Inc(1) scope.Timer("storage_duration").Record(time.Since(storageStart)) @@ -141,7 +133,7 @@ func (c *controller) getGraph(ctx context.Context, buildDescription *pb.BuildDes } } } else { - logger.Info("getGraph: bypass_cache=true, skipping cache lookup") + logger.Debug("getGraph: bypass_cache=true, skipping cache lookup") } computeStart := time.Now() graphReader, err := c.orchestrator.GetTargetGraph(ctx, orchestrator.GetTargetGraphParam{Req: &pb.GetTargetGraphRequest{BuildDescription: buildDescription, OutputConfig: outputConfig, RequestOptions: requestOptions}, BypassCache: bypassCache}) @@ -155,10 +147,6 @@ func (c *controller) getGraph(ctx context.Context, buildDescription *pb.BuildDes } return nil, common.WithReason(failureReasonGraphFetch, common.ErrorTypeInfra, err) } - logger.Info("getGraph: computed target graph", - zap.Duration("compute_duration", time.Since(computeStart)), - zap.Duration("total_duration", time.Since(start)), - ) scope := c.scope.SubScope("get_graph") scope.Timer("compute_duration").Record(time.Since(computeStart)) scope.Timer("total_duration").Record(time.Since(start)) diff --git a/orchestrator/native_orchestrator.go b/orchestrator/native_orchestrator.go index fda7ea3..0b065b2 100644 --- a/orchestrator/native_orchestrator.go +++ b/orchestrator/native_orchestrator.go @@ -112,7 +112,6 @@ func (b *nativeOrchestrator) GetTargetGraph(ctx context.Context, param GetTarget } }() logger := b.logger.With(zap.Any("build_description", param.Req.BuildDescription)) - logger.Infow("GetTargetGraph: Processing request") // parse the config file cfg, err := config.Parse(b.configFilePath) @@ -140,7 +139,6 @@ func (b *nativeOrchestrator) GetTargetGraph(ctx context.Context, param GetTarget if err != nil { return nil, fmt.Errorf("checkout %s@%s: %w", param.Req.BuildDescription.Remote, param.Req.BuildDescription.BaseSha, err) } - logger.Infow("GetTargetGraph: Checked out base revision") requests := make([]workspace.Request, 0, len(param.Req.BuildDescription.Requests)) factory := b.gitFactory @@ -160,7 +158,6 @@ func (b *nativeOrchestrator) GetTargetGraph(ctx context.Context, param GetTarget if err != nil { return nil, fmt.Errorf("apply requests: %w", err) } - logger.Infow("GetTargetGraph: Applied requests", zap.Int("request_count", len(requests))) // Compute the treehash and download the target graph from storage if exists. treehash, err := gitModule.RevParse(ctx, "HEAD^{tree}") @@ -171,15 +168,13 @@ func (b *nativeOrchestrator) GetTargetGraph(ctx context.Context, param GetTarget if !param.BypassCache { graphReader, err := storage.NewGraphReader(ctx, b.storage, treehashPath) if err == nil { - logger.Infow("GetTargetGraph: Cache hit on treehash", zap.String("treehash", treehash)) return graphReader, nil } if !storage.IsNotFound(err) { return nil, fmt.Errorf("read graph at treehash %s: %w", treehash, err) } - logger.Infow("GetTargetGraph: Treehash not found, computing target graph", zap.String("treehash", treehash)) } else { - logger.Infow("GetTargetGraph: bypass_cache=true, computing target graph") + logger.Debugw("GetTargetGraph: bypass_cache=true") } // Compute the target graph and store it in storage. runner := b.graphRunner @@ -225,6 +220,5 @@ func (b *nativeOrchestrator) GetTargetGraph(ctx context.Context, param GetTarget if err != nil { return nil, fmt.Errorf("create graph reader at %s: %w", treehashPath, err) } - logger.Infow("GetTargetGraph: Done computing and storing target graph", zap.String("treehash", treehash)) return graphReader, nil } From 6d784ffc7cc8e9a8b883726b1fb26c1bc16e79e2 Mon Sep 17 00:00:00 2001 From: Yushan Lin Date: Thu, 2 Jul 2026 10:05:07 -0700 Subject: [PATCH 7/9] Update --- controller/getchangedtargets.go | 13 ++++++++++++- controller/gettargetgraph.go | 21 +++++++++------------ controller/gettargetgraph_test.go | 17 ++++------------- 3 files changed, 25 insertions(+), 26 deletions(-) diff --git a/controller/getchangedtargets.go b/controller/getchangedtargets.go index 59af489..8823878 100644 --- a/controller/getchangedtargets.go +++ b/controller/getchangedtargets.go @@ -48,12 +48,12 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str if retErr != nil { scope.Counter("failure").Inc(1) emitFailureMetric(scope, retErr) - logger.Error("GetChangedTargets failed", zap.Error(retErr)) } else { scope.Counter("success").Inc(1) } }() if err := validateGetChangedTargetsRequest(request); err != nil { + logger.Error("GetChangedTargets: validation failed", zap.Error(err)) return fmt.Errorf("validate request: %w", err) } scope = scope.Tagged(map[string]string{"repo": common.ToShortRemote(request.GetFirstRevision().GetRemote())}) @@ -82,12 +82,14 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str cacheStart := time.Now() treehash1, treehash2, err := readTreehashParallel(ctx, c.storage, request.GetFirstRevision(), request.GetSecondRevision()) if err != nil { + logger.Error("GetChangedTargets: failed to read revision treehash", zap.Error(err)) return fmt.Errorf("read revision treehash: %w", err) } if treehash1 != "" && treehash2 != "" { cacheKey := common.GetComparedTargetsCachePath(request.GetFirstRevision().GetRemote(), treehash1, treehash2, request.GetRequestOptions()) cachedReader, cacheErr := storage.NewChangedTargetsReader(ctx, c.storage, cacheKey) if cacheErr != nil && !storage.IsNotFound(cacheErr) { + logger.Error("GetChangedTargets: failed to read from cache", zap.Error(cacheErr)) return fmt.Errorf("failed to read from cache: %w", cacheErr) } else if cachedReader != nil { // Buffer all responses before sending any. A concurrent goroutine write may have @@ -98,6 +100,7 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str for { if err := ctx.Err(); err != nil { if closeErr := cachedReader.Close(); closeErr != nil { + logger.Error("GetChangedTargets: failed to close cached reader", zap.Error(closeErr)) return fmt.Errorf("close cached reader: %w (original: %w)", closeErr, err) } return err @@ -114,16 +117,19 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str cached = append(cached, resp) } if closeErr := cachedReader.Close(); closeErr != nil { + logger.Error("GetChangedTargets: failed to close cached reader", zap.Error(closeErr)) return fmt.Errorf("close cached reader: %w", closeErr) } if readErr != nil { + logger.Error("GetChangedTargets: failed to read cached response", zap.Error(readErr)) return fmt.Errorf("read cached response: %w", readErr) } cacheReadDuration := time.Since(cacheStart) scope.Counter("changed_targets_cache_hit").Inc(1) scope.Timer("cache_read_duration").Record(cacheReadDuration) if sendErr := sendTrimmedChangedTargets(stream, cached, maxDist, request.GetOutputConfig()); sendErr != nil { + logger.Error("GetChangedTargets: failed to send cached response", zap.Error(sendErr)) return fmt.Errorf("failed to send cached response: %w", sendErr) } totalDuration := time.Since(start) @@ -219,6 +225,7 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str scope.Timer("graph_fetch_duration").Record(graphFetchDuration) if ctx.Err() != nil { + logger.Error("GetChangedTargets: context cancelled", zap.Error(ctx.Err())) return ctx.Err() } @@ -235,6 +242,7 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str } if err != nil { + logger.Error("GetChangedTargets: failed to get target graphs", zap.Error(err)) return err } firstGraph := jobs[0].graphStreamChunks @@ -250,8 +258,10 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str secondGraph = nil if err != nil { if ctx.Err() != nil { + logger.Error("GetChangedTargets: context cancelled during compare", zap.Error(ctx.Err())) return ctx.Err() } + logger.Error("GetChangedTargets: failed to compare target graphs", zap.Error(err)) return fmt.Errorf("failed to compare target graphs: %w", err) } compareDuration := time.Since(compareStart) @@ -291,6 +301,7 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str sendStart := time.Now() if err := sendTrimmedChangedTargets(stream, changedTargetsResponses, maxDist, request.GetOutputConfig()); err != nil { + logger.Error("GetChangedTargets: failed to send response", zap.Error(err)) return fmt.Errorf("failed to send response: %w", err) } sendDuration := time.Since(sendStart) diff --git a/controller/gettargetgraph.go b/controller/gettargetgraph.go index e8eb453..03c9209 100644 --- a/controller/gettargetgraph.go +++ b/controller/gettargetgraph.go @@ -43,7 +43,6 @@ func (c *controller) GetTargetGraph(request *pb.GetTargetGraphRequest, stream pb if retErr != nil { scope.Counter("failure").Inc(1) emitFailureMetric(scope, retErr) - logger.Error("GetTargetGraph failed", zap.Error(retErr)) } else { scope.Counter("success").Inc(1) } @@ -51,6 +50,7 @@ func (c *controller) GetTargetGraph(request *pb.GetTargetGraphRequest, stream pb scope = scope.Tagged(map[string]string{"repo": common.ToShortRemote(request.GetBuildDescription().GetRemote())}) graphReader, err := c.getGraph(ctx, request.GetBuildDescription(), request.GetOutputConfig(), request.GetRequestOptions(), request.GetBypassCache()) if err != nil { + logger.Error("GetTargetGraph: failed to get graph", zap.Error(err)) return err } if graphReader == nil { @@ -70,11 +70,13 @@ func (c *controller) GetTargetGraph(request *pb.GetTargetGraphRequest, stream pb return nil } if err != nil { + logger.Error("GetTargetGraph: failed to read graph stream", zap.Error(err)) return common.WithReason(failureReasonGraphFetch, common.ErrorTypeInfra, err) } toSend := applyOptimizedTargetsOutputConfigToChunk(graphStreamChunk, outputConfig) err = stream.Send(toSend) if err != nil { + logger.Error("GetTargetGraph: failed to send graph", zap.Error(err)) return common.WithReason(failureReasonSend, common.ErrorTypeInfra, fmt.Errorf("send graph: %w", err)) } } @@ -103,14 +105,13 @@ func (c *controller) getGraph(ctx context.Context, buildDescription *pb.BuildDes // Cache miss - blob doesn't exist, need to compute and store target graph logger.Debug("getGraph: treehash not found", zap.Error(err)) } else { - // Other errors (network, infra issues) should be retried - return nil, err + return nil, fmt.Errorf("storage error reading treehash: %w", err) } } else { defer treehashResponse.ReadCloser.Close() treehashBytes, err := io.ReadAll(treehashResponse.ReadCloser) if err != nil { - return nil, err + return nil, fmt.Errorf("read treehash: %w", err) } treehashPath := common.GetGraphByTreeHash(buildDescription.GetRemote(), string(treehashBytes), buildDescription.GetStrategy(), requestOptions) // Download the target graph based on treehash. @@ -118,10 +119,10 @@ func (c *controller) getGraph(ctx context.Context, buildDescription *pb.BuildDes graphReader, err := storage.NewGraphReader(ctx, c.storage, treehashPath) if err != nil { if ctx.Err() != nil { - return nil, common.WithReason(common.FailureReasonCancelled, common.ErrorTypeUser, ctx.Err()) + return nil, fmt.Errorf("context cancelled: %w", ctx.Err()) } if !storage.IsNotFound(err) { - return nil, common.WithReason(failureReasonGraphFetch, common.ErrorTypeInfra, err) + return nil, fmt.Errorf("read graph from storage: %w", err) } logger.Warn("getGraph: graph not found at treehash path", zap.Error(err)) } else { @@ -139,13 +140,9 @@ func (c *controller) getGraph(ctx context.Context, buildDescription *pb.BuildDes graphReader, err := c.orchestrator.GetTargetGraph(ctx, orchestrator.GetTargetGraphParam{Req: &pb.GetTargetGraphRequest{BuildDescription: buildDescription, OutputConfig: outputConfig, RequestOptions: requestOptions}, BypassCache: bypassCache}) if err != nil { if ctx.Err() != nil { - return nil, common.WithReason(common.FailureReasonCancelled, common.ErrorTypeUser, ctx.Err()) + return nil, fmt.Errorf("context cancelled: %w", ctx.Err()) } - var ce common.ClassifiedError - if errors.As(err, &ce) { - return nil, err - } - return nil, common.WithReason(failureReasonGraphFetch, common.ErrorTypeInfra, err) + return nil, fmt.Errorf("compute target graph: %w", err) } scope := c.scope.SubScope("get_graph") scope.Timer("compute_duration").Record(time.Since(computeStart)) diff --git a/controller/gettargetgraph_test.go b/controller/gettargetgraph_test.go index e62856f..ce626e8 100644 --- a/controller/gettargetgraph_test.go +++ b/controller/gettargetgraph_test.go @@ -24,7 +24,6 @@ import ( gogio "github.com/gogo/protobuf/io" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" - "github.com/uber/tango/core/common" "github.com/uber/tango/core/storage" storagemock "github.com/uber/tango/core/storage/storagemock" orchestratormock "github.com/uber/tango/orchestrator/orchestratormock" @@ -248,10 +247,8 @@ func TestGetTargetGraph_GraphFetchError(t *testing.T) { BuildDescription: &pb.BuildDescription{Remote: "repo:go-code", BaseSha: "sha"}, }, stream) require.Error(t, err) - var ce common.ClassifiedError - require.True(t, errors.As(err, &ce)) - assert.Equal(t, failureReasonGraphFetch, ce.Reason()) - assert.Equal(t, common.ErrorTypeInfra, ce.Type()) + assert.Contains(t, err.Error(), "read graph from storage") + assert.Contains(t, err.Error(), "graph error") } // New coverage: io.ReadFrom fails on graph read -> error returned. @@ -351,10 +348,7 @@ func TestGetTargetGraph_GraphReadCancelled(t *testing.T) { BuildDescription: &pb.BuildDescription{Remote: "repo:go-code", BaseSha: "sha"}, }, stream) require.Error(t, err) - var ce common.ClassifiedError - require.True(t, errors.As(err, &ce)) - assert.Equal(t, common.FailureReasonCancelled, ce.Reason()) - assert.Equal(t, common.ErrorTypeUser, ce.Type()) + assert.Contains(t, err.Error(), "context cancelled") } func TestGetTargetGraph_OrchestratorCancelled(t *testing.T) { @@ -376,10 +370,7 @@ func TestGetTargetGraph_OrchestratorCancelled(t *testing.T) { BuildDescription: &pb.BuildDescription{Remote: "repo:go-code", BaseSha: "sha"}, }, stream) require.Error(t, err) - var ce common.ClassifiedError - require.True(t, errors.As(err, &ce)) - assert.Equal(t, common.FailureReasonCancelled, ce.Reason()) - assert.Equal(t, common.ErrorTypeUser, ce.Type()) + assert.Contains(t, err.Error(), "context cancelled") } func newMockReadCloser(data []byte) io.ReadCloser { From 1f4c93f0cdde075c3f1ab168e4a6daf57c0df5d8 Mon Sep 17 00:00:00 2001 From: Yushan Lin Date: Thu, 2 Jul 2026 10:18:52 -0700 Subject: [PATCH 8/9] Update --- controller/getchangedtargets.go | 3 --- controller/gettargetgraph.go | 9 +-------- orchestrator/native_orchestrator.go | 2 -- 3 files changed, 1 insertion(+), 13 deletions(-) diff --git a/controller/getchangedtargets.go b/controller/getchangedtargets.go index 8823878..264a960 100644 --- a/controller/getchangedtargets.go +++ b/controller/getchangedtargets.go @@ -100,7 +100,6 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str for { if err := ctx.Err(); err != nil { if closeErr := cachedReader.Close(); closeErr != nil { - logger.Error("GetChangedTargets: failed to close cached reader", zap.Error(closeErr)) return fmt.Errorf("close cached reader: %w (original: %w)", closeErr, err) } return err @@ -225,7 +224,6 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str scope.Timer("graph_fetch_duration").Record(graphFetchDuration) if ctx.Err() != nil { - logger.Error("GetChangedTargets: context cancelled", zap.Error(ctx.Err())) return ctx.Err() } @@ -258,7 +256,6 @@ func (c *controller) GetChangedTargets(request *pb.GetChangedTargetsRequest, str secondGraph = nil if err != nil { if ctx.Err() != nil { - logger.Error("GetChangedTargets: context cancelled during compare", zap.Error(ctx.Err())) return ctx.Err() } logger.Error("GetChangedTargets: failed to compare target graphs", zap.Error(err)) diff --git a/controller/gettargetgraph.go b/controller/gettargetgraph.go index 03c9209..b947062 100644 --- a/controller/gettargetgraph.go +++ b/controller/gettargetgraph.go @@ -93,17 +93,13 @@ func (c *controller) getGraph(ctx context.Context, buildDescription *pb.BuildDes if buildDescription.GetBaseSha() == "" || buildDescription.GetRemote() == "" { return nil, fmt.Errorf("build description is missing required fields: base_sha: %s, remote: %s", buildDescription.GetBaseSha(), buildDescription.GetRemote()) } - logger := c.logger.With( - zap.Any("build_description", buildDescription), - ) if !bypassCache { // Look up the the git treehash based on cache path treehashCachePath := common.GetTreehashCachePath(buildDescription) treehashResponse, err := c.storage.Get(ctx, storage.DownloadRequest{Key: treehashCachePath}) if err != nil { if storage.IsNotFound(err) { - // Cache miss - blob doesn't exist, need to compute and store target graph - logger.Debug("getGraph: treehash not found", zap.Error(err)) + // Cache miss - fall through to compute } else { return nil, fmt.Errorf("storage error reading treehash: %w", err) } @@ -124,7 +120,6 @@ func (c *controller) getGraph(ctx context.Context, buildDescription *pb.BuildDes if !storage.IsNotFound(err) { return nil, fmt.Errorf("read graph from storage: %w", err) } - logger.Warn("getGraph: graph not found at treehash path", zap.Error(err)) } else { scope := c.scope.SubScope("get_graph") scope.Counter("graph_cache_hit").Inc(1) @@ -133,8 +128,6 @@ func (c *controller) getGraph(ctx context.Context, buildDescription *pb.BuildDes return graphReader, nil } } - } else { - logger.Debug("getGraph: bypass_cache=true, skipping cache lookup") } computeStart := time.Now() graphReader, err := c.orchestrator.GetTargetGraph(ctx, orchestrator.GetTargetGraphParam{Req: &pb.GetTargetGraphRequest{BuildDescription: buildDescription, OutputConfig: outputConfig, RequestOptions: requestOptions}, BypassCache: bypassCache}) diff --git a/orchestrator/native_orchestrator.go b/orchestrator/native_orchestrator.go index 0b065b2..7721317 100644 --- a/orchestrator/native_orchestrator.go +++ b/orchestrator/native_orchestrator.go @@ -173,8 +173,6 @@ func (b *nativeOrchestrator) GetTargetGraph(ctx context.Context, param GetTarget if !storage.IsNotFound(err) { return nil, fmt.Errorf("read graph at treehash %s: %w", treehash, err) } - } else { - logger.Debugw("GetTargetGraph: bypass_cache=true") } // Compute the target graph and store it in storage. runner := b.graphRunner From 30fc0413b01b21d90bb65a51a5469b586225e7bc Mon Sep 17 00:00:00 2001 From: Yushan Lin Date: Thu, 2 Jul 2026 10:30:11 -0700 Subject: [PATCH 9/9] Update --- controller/getchangedtargets_test.go | 20 ++++++++++---------- 1 file changed, 10 insertions(+), 10 deletions(-) diff --git a/controller/getchangedtargets_test.go b/controller/getchangedtargets_test.go index 31026a6..1f1c18a 100644 --- a/controller/getchangedtargets_test.go +++ b/controller/getchangedtargets_test.go @@ -145,7 +145,7 @@ func TestCompareTargetGraphs(t *testing.T) { }, } - response, err := c.compareTargetGraphs(context.Background(),[]*pb.GetTargetGraphResponse{firstGraph}, []*pb.GetTargetGraphResponse{secondGraph}, -1) + response, err := c.compareTargetGraphs(context.Background(), []*pb.GetTargetGraphResponse{firstGraph}, []*pb.GetTargetGraphResponse{secondGraph}, -1) require.NoError(t, err) require.NotNil(t, response) } @@ -606,7 +606,7 @@ func TestCompareTargetGraphs_NewTarget_CanonicalIDs(t *testing.T) { }, }, } - res, err := c.compareTargetGraphs(context.Background(),first, second, -1) + res, err := c.compareTargetGraphs(context.Background(), first, second, -1) require.NoError(t, err) require.Len(t, res, 2) cs := res[0].GetChangedTargets() @@ -678,7 +678,7 @@ func TestCompareTargetGraphs_SourceFileDirectAndPropagation(t *testing.T) { }, }, } - res, err := c.compareTargetGraphs(context.Background(),first, second, -1) + res, err := c.compareTargetGraphs(context.Background(), first, second, -1) require.NoError(t, err) cs := res[0].GetChangedTargets() require.NotNil(t, cs) @@ -751,7 +751,7 @@ func TestCompareTargetGraphs_ChangedRuleUnreachableFromAnySeed(t *testing.T) { // Hash-only change on a rule with no own-config change and no reachable // seed: under "trust the hasher" semantics, an orphan CHANGED rule with // no upstream explanation becomes a distance-0 seed itself. - res, err := c.compareTargetGraphs(context.Background(),first, second, -1) + res, err := c.compareTargetGraphs(context.Background(), first, second, -1) require.NoError(t, err) cs := res[0].GetChangedTargets() require.NotNil(t, cs) @@ -818,7 +818,7 @@ func TestCompareTargetGraphs_ChangedWhenDependenciesChanged(t *testing.T) { }, }, } - res, err := c.compareTargetGraphs(context.Background(),first, second, -1) + res, err := c.compareTargetGraphs(context.Background(), first, second, -1) require.NoError(t, err) cs := res[0].GetChangedTargets() require.NotNil(t, cs) @@ -900,7 +900,7 @@ func TestCompareTargetGraphs_ChangedWhenAttributesChanged(t *testing.T) { }, }, } - res, err := c.compareTargetGraphs(context.Background(),first, second, -1) + res, err := c.compareTargetGraphs(context.Background(), first, second, -1) require.NoError(t, err) cs := res[0].GetChangedTargets() require.NotNil(t, cs) @@ -982,7 +982,7 @@ func TestCompareTargetGraphs_ChangedWhenNewAttributeAdded(t *testing.T) { }, }, } - res, err := c.compareTargetGraphs(context.Background(),first, second, -1) + res, err := c.compareTargetGraphs(context.Background(), first, second, -1) require.NoError(t, err) cs := res[0].GetChangedTargets() require.NotNil(t, cs) @@ -1322,7 +1322,7 @@ func TestCompareTargetGraphs_HashOnlyChangePropagatesViaBFS(t *testing.T) { }, }, } - res, err := c.compareTargetGraphs(context.Background(),first, second, -1) + res, err := c.compareTargetGraphs(context.Background(), first, second, -1) require.NoError(t, err) cs := res[0].GetChangedTargets() require.NotNil(t, cs) @@ -1404,7 +1404,7 @@ func TestCompareTargetGraphs_SiblingRuleNotPromotedToSeed(t *testing.T) { }, }, } - res, err := c.compareTargetGraphs(context.Background(),first, second, -1) + res, err := c.compareTargetGraphs(context.Background(), first, second, -1) require.NoError(t, err) cs := res[0].GetChangedTargets() require.NotNil(t, cs) @@ -1458,7 +1458,7 @@ func TestCompareTargetGraphs_DeletedTargetEmitted(t *testing.T) { }, }, } - res, err := c.compareTargetGraphs(context.Background(),first, second, -1) + res, err := c.compareTargetGraphs(context.Background(), first, second, -1) require.NoError(t, err) cs := res[0].GetChangedTargets() require.NotNil(t, cs)