From 25416e9be7336efc8aafd087341d2037914afec2 Mon Sep 17 00:00:00 2001 From: Giteabot Date: Thu, 1 Oct 2026 03:19:33 -0700 Subject: [PATCH] fix: trace git command correctly (#39520) (#39524) Backport #39520 by @wxiaoguang Help #39410 Co-authored-by: wxiaoguang --- modules/git/gitcmd/command.go | 15 ++++++++++----- modules/git/gitcmd/context.go | 2 +- modules/gtprof/trace.go | 2 ++ modules/gtprof/trace_const.go | 11 +++++++---- routers/api/v1/repo/pull.go | 2 +- routers/web/repo/pull.go | 2 +- services/automerge/automerge.go | 2 +- services/pull/merge.go | 17 ++++++++++++++++- tests/integration/pull_merge_test.go | 12 ++++++------ 9 files changed, 45 insertions(+), 20 deletions(-) diff --git a/modules/git/gitcmd/command.go b/modules/git/gitcmd/command.go index e8ec12ebc6c..5167a5a748d 100644 --- a/modules/git/gitcmd/command.go +++ b/modules/git/gitcmd/command.go @@ -49,8 +49,8 @@ type Command struct { cmd *process.Cmd cmdCtx context.Context - cmdCancel process.CancelCauseFunc - cmdFinished process.FinishedFunc + cmdCtxCancel process.CancelCauseFunc + cmdFinished func() cmdStartTime time.Time pipelineFunc func(Context) error @@ -428,19 +428,24 @@ func (c *Command) Start(ctx context.Context) (retErr error) { if c.callerInfo == "" { c.WithParentCallerInfo() } + // these logs are for debugging purposes only, so no guarantee of correctness or stability desc := fmt.Sprintf("git.Run(by:%s, repo:%s): %s", c.callerInfo, logArgSanitize(c.gitDir), cmdLogString) log.Debug("git.Command: %s", desc) _, span := gtprof.GetTracer().Start(ctx, gtprof.TraceSpanGitRun) - defer span.End() span.SetAttributeString(gtprof.TraceAttrFuncCaller, c.callerInfo) span.SetAttributeString(gtprof.TraceAttrGitCommand, cmdLogString) + var cmdCtxFinished func() if c.cmdTimeout <= 0 { - c.cmdCtx, c.cmdCancel, c.cmdFinished = process.GetManager().AddContext(ctx, desc) + c.cmdCtx, c.cmdCtxCancel, cmdCtxFinished = process.GetManager().AddContext(ctx, desc) } else { - c.cmdCtx, c.cmdCancel, c.cmdFinished = process.GetManager().AddContextTimeout(ctx, c.cmdTimeout, desc) + c.cmdCtx, c.cmdCtxCancel, cmdCtxFinished = process.GetManager().AddContextTimeout(ctx, c.cmdTimeout, desc) + } + c.cmdFinished = func() { + cmdCtxFinished() + span.End() } c.cmdStartTime = time.Now() diff --git a/modules/git/gitcmd/context.go b/modules/git/gitcmd/context.go index a32f92ff3aa..e23bc268ca6 100644 --- a/modules/git/gitcmd/context.go +++ b/modules/git/gitcmd/context.go @@ -27,6 +27,6 @@ func (c *cmdContext) CancelPipeline(err error) error { // * context canceled by pipeline caller with/without error (normal cancellation) // * context canceled by parent context (still context.Canceled error) // * other causes - c.cmd.cmdCancel(pipelineError{err}) + c.cmd.cmdCtxCancel(pipelineError{err}) return err } diff --git a/modules/gtprof/trace.go b/modules/gtprof/trace.go index 370078516ea..6b5e519162a 100644 --- a/modules/gtprof/trace.go +++ b/modules/gtprof/trace.go @@ -122,6 +122,8 @@ func (t *Tracer) Start(ctx context.Context, spanName string) (context.Context, * ts.parent = parentSpan } + // FIXME: this ctx handling is not right. The returned ctx should inherit the ctx passed in, but not from span's internal contexts + // The returned ctx only needs to inherit the values of the internal contexts of spans parentCtx := ctx for internalSpanIdx, tsp := range starters { var internalSpan traceSpanInternal diff --git a/modules/gtprof/trace_const.go b/modules/gtprof/trace_const.go index af9ce9223fd..44088a952f3 100644 --- a/modules/gtprof/trace_const.go +++ b/modules/gtprof/trace_const.go @@ -6,14 +6,17 @@ package gtprof // Some interesting names could be found in https://github.com/open-telemetry/opentelemetry-go/tree/main/semconv const ( + TraceSpanContext = "context" TraceSpanHTTP = "http" TraceSpanGitRun = "git-run" TraceSpanDatabase = "database" ) const ( - TraceAttrFuncCaller = "func.caller" - TraceAttrDbSQL = "db.sql" - TraceAttrGitCommand = "git.command" - TraceAttrHTTPRoute = "http.route" + TraceAttrGeneralName = "general.name" + TraceAttrGeneralDesc = "general.desc" + TraceAttrFuncCaller = "func.caller" + TraceAttrDbSQL = "db.sql" + TraceAttrGitCommand = "git.command" + TraceAttrHTTPRoute = "http.route" ) diff --git a/routers/api/v1/repo/pull.go b/routers/api/v1/repo/pull.go index 83bb07aabca..0063287f77f 100644 --- a/routers/api/v1/repo/pull.go +++ b/routers/api/v1/repo/pull.go @@ -1032,7 +1032,7 @@ func MergePullRequest(ctx *context.APIContext) { } } - if err := pull_service.Merge(pr.ID, ctx.Doer, repo_model.MergeStyle(form.Do), form.HeadCommitID, message, false); err != nil { + if err := pull_service.Merge(ctx, pr.ID, ctx.Doer, repo_model.MergeStyle(form.Do), form.HeadCommitID, message, false); err != nil { if pull_service.IsErrInvalidMergeStyle(err) { ctx.APIError(http.StatusMethodNotAllowed, fmt.Sprintf("%s is not allowed an allowed merge style for this repository", repo_model.MergeStyle(form.Do))) } else if conflictError, ok := err.(pull_service.ErrMergeConflicts); ok { diff --git a/routers/web/repo/pull.go b/routers/web/repo/pull.go index e99667a0d14..53fd535ea6c 100644 --- a/routers/web/repo/pull.go +++ b/routers/web/repo/pull.go @@ -1145,7 +1145,7 @@ func MergePullRequest(ctx *context.Context) { } } - if err := pull_service.Merge(pr.ID, ctx.Doer, repo_model.MergeStyle(form.Do), form.HeadCommitID, message, false); err != nil { + if err := pull_service.Merge(ctx, pr.ID, ctx.Doer, repo_model.MergeStyle(form.Do), form.HeadCommitID, message, false); err != nil { if pull_service.IsErrInvalidMergeStyle(err) { ctx.JSONError(ctx.Tr("repo.pulls.invalid_merge_option")) } else if conflictError, ok := err.(pull_service.ErrMergeConflicts); ok { diff --git a/services/automerge/automerge.go b/services/automerge/automerge.go index 39b4b9efc9f..36ce6caf273 100644 --- a/services/automerge/automerge.go +++ b/services/automerge/automerge.go @@ -224,7 +224,7 @@ func handlePullRequestAutoMerge(ctx context.Context, pr *issues_model.PullReques // although expectedHeadCommitID is checked before, we should pass it to the Merge function to // make it be checked again in case the head commit id changed after the previous check. - if err := pull_service.Merge(pr.ID, doer, scheduledPRM.MergeStyle, expectedHeadCommitID, scheduledPRM.Message, true); err != nil { + if err := pull_service.Merge(ctx, pr.ID, doer, scheduledPRM.MergeStyle, expectedHeadCommitID, scheduledPRM.Message, true); err != nil { if pull_service.IsErrSHADoesNotMatch(err) { return errors.Join(errSkipAutoMerge, err) } diff --git a/services/pull/merge.go b/services/pull/merge.go index f091ce4629c..cb3e51d9336 100644 --- a/services/pull/merge.go +++ b/services/pull/merge.go @@ -14,6 +14,7 @@ import ( "strconv" "strings" "unicode" + "uuid" "gitea.dev/models/db" git_model "gitea.dev/models/git" @@ -27,6 +28,7 @@ import ( "gitea.dev/modules/git/gitcmd" "gitea.dev/modules/globallock" "gitea.dev/modules/graceful" + "gitea.dev/modules/gtprof" "gitea.dev/modules/httplib" "gitea.dev/modules/log" "gitea.dev/modules/references" @@ -289,9 +291,22 @@ func hasPullRequestCommitBeenMerged(ctx context.Context, pr *issues_model.PullRe // Merge merges pull request to base repository. // Caller should check PR is ready to be merged (review and status checks) -func Merge(prID int64, doer *user_model.User, mergeStyle repo_model.MergeStyle, expectedHeadCommitID, message string, wasAutoMerged bool) error { +func Merge(outerCtx context.Context, prID int64, doer *user_model.User, mergeStyle repo_model.MergeStyle, expectedHeadCommitID, message string, wasAutoMerged bool) error { + outerCtxId := uuid.NewV4().String() + + _, outerSpan := gtprof.GetTracer().Start(outerCtx, gtprof.TraceSpanContext) + outerSpan.SetAttributeString("context.trace-id", outerCtxId) // this attribute is only used internally for debugging purpose + defer outerSpan.End() + + // TODO: in the future, the contexts from graceful.GetManager() should be wrapped with gtprof tracing, refactor the code to framework-level support ctx := graceful.GetManager().HammerContext() // don't abort the git operation even if the user's request is canceled + ctx, span := gtprof.GetTracer().Start(ctx, gtprof.TraceSpanContext) + span.SetAttributeString(gtprof.TraceAttrGeneralName, "merge-pull-request") + span.SetAttributeString(gtprof.TraceAttrGeneralDesc, fmt.Sprintf("merge pull request %d with merge style %s", prID, mergeStyle)) + span.SetAttributeString("context.trace-id-outer", outerCtxId) // this attribute is only used internally for debugging purpose + defer span.End() + err := globallock.LockAndDo(ctx, getPullWorkingLockKey(prID), func(ctx context.Context) error { pr, err := issues_model.GetPullRequestByID(ctx, prID) if err != nil { diff --git a/tests/integration/pull_merge_test.go b/tests/integration/pull_merge_test.go index e6e3f8f08c5..32f78cfb5ae 100644 --- a/tests/integration/pull_merge_test.go +++ b/tests/integration/pull_merge_test.go @@ -378,11 +378,11 @@ func TestCantMergeConflict(t *testing.T) { BaseBranch: "base", }) - err := pull_service.Merge(pr.ID, user1, repo_model.MergeStyleMerge, "", "CONFLICT", false) + err := pull_service.Merge(t.Context(), pr.ID, user1, repo_model.MergeStyleMerge, "", "CONFLICT", false) assert.Error(t, err, "Merge should return an error due to conflict") assert.True(t, pull_service.IsErrMergeConflicts(err), "Merge error is not a conflict error") - err = pull_service.Merge(pr.ID, user1, repo_model.MergeStyleRebase, "", "CONFLICT", false) + err = pull_service.Merge(t.Context(), pr.ID, user1, repo_model.MergeStyleRebase, "", "CONFLICT", false) assert.Error(t, err, "Merge should return an error due to conflict") assert.True(t, pull_service.IsErrRebaseConflicts(err), "Merge error is not a conflict error") }) @@ -473,7 +473,7 @@ func TestCantMergeUnrelated(t *testing.T) { BaseBranch: "base", }) - err = pull_service.Merge(pr.ID, user1, repo_model.MergeStyleMerge, "", "UNRELATED", false) + err = pull_service.Merge(t.Context(), pr.ID, user1, repo_model.MergeStyleMerge, "", "UNRELATED", false) assert.Error(t, err, "Merge should return an error due to unrelated") assert.True(t, pull_service.IsErrMergeUnrelatedHistories(err), "Merge error is not a unrelated histories error") }) @@ -509,7 +509,7 @@ func TestFastForwardOnlyMerge(t *testing.T) { BaseBranch: "master", }) - err := pull_service.Merge(pr.ID, user1, repo_model.MergeStyleFastForwardOnly, "", "FAST-FORWARD-ONLY", false) + err := pull_service.Merge(t.Context(), pr.ID, user1, repo_model.MergeStyleFastForwardOnly, "", "FAST-FORWARD-ONLY", false) assert.NoError(t, err) }) } @@ -596,7 +596,7 @@ func TestFastForwardOnlyMergeWithRequiredSignedCommits(t *testing.T) { pb.RequireSignedCommits = false require.NoError(t, git_model.UpdateProtectBranch(t.Context(), repo1, pb, git_model.WhitelistOptions{})) - require.NoError(t, pull_service.Merge(pr.ID, user1, repo_model.MergeStyleFastForwardOnly, "", "FAST-FORWARD-ONLY", false)) + require.NoError(t, pull_service.Merge(t.Context(), pr.ID, user1, repo_model.MergeStyleFastForwardOnly, "", "FAST-FORWARD-ONLY", false)) }) } @@ -631,7 +631,7 @@ func TestCantFastForwardOnlyMergeDiverging(t *testing.T) { BaseBranch: "master", }) - err := pull_service.Merge(pr.ID, user1, repo_model.MergeStyleFastForwardOnly, "", "DIVERGING", false) + err := pull_service.Merge(t.Context(), pr.ID, user1, repo_model.MergeStyleFastForwardOnly, "", "DIVERGING", false) assert.Error(t, err, "Merge should return an error due to being for a diverging branch") assert.True(t, pull_service.IsErrMergeDivergingFastForwardOnly(err), "Merge error is not a diverging fast-forward-only error") })