From 7efd24b28f743acca543617ef00a921329644ae7 Mon Sep 17 00:00:00 2001 From: silverwind Date: Wed, 16 Sep 2026 08:53:15 +0200 Subject: [PATCH] fix(actions): use gitea's clock for actions durations (#39323) --- models/actions/run.go | 5 ++++- models/actions/run_attempt.go | 4 ++++ models/actions/task.go | 23 +++++++--------------- models/actions/task_test.go | 9 +++++++-- routers/web/devtest/mock_actions.go | 5 ++--- routers/web/repo/actions/view.go | 15 ++++++-------- web_src/js/components/ActionRunJobView.vue | 9 ++++++--- 7 files changed, 36 insertions(+), 34 deletions(-) diff --git a/models/actions/run.go b/models/actions/run.go index ff91d36d004..d4cc9665d43 100644 --- a/models/actions/run.go +++ b/models/actions/run.go @@ -174,7 +174,10 @@ func (run *ActionRun) LoadRepo(ctx context.Context) error { } func (run *ActionRun) Duration() time.Duration { - d := calculateDuration(run.Started, run.Stopped, run.Status, run.Updated) + run.PreviousDuration + d := calculateDuration(run.Started, run.Stopped, run.Status, run.Updated) + if run.LatestAttemptID == 0 { + d += run.PreviousDuration + } if d < 0 { return 0 } diff --git a/models/actions/run_attempt.go b/models/actions/run_attempt.go index 3e15c8c6a9b..73298cfe33e 100644 --- a/models/actions/run_attempt.go +++ b/models/actions/run_attempt.go @@ -163,6 +163,10 @@ func UpdateRunAttempt(ctx context.Context, attempt *ActionRunAttempt, cols ...st attempt.Started = timeutil.TimeStampNow() cols = append(cols, "started") } + if slices.Contains(cols, "status") && !attempt.Stopped.IsZero() && !attempt.Status.IsDone() { + attempt.Stopped = 0 + cols = append(cols, "stopped") + } sess := db.GetEngine(ctx).ID(attempt.ID) if len(cols) > 0 { diff --git a/models/actions/task.go b/models/actions/task.go index 9a99a32faae..f4b8a4a54fe 100644 --- a/models/actions/task.go +++ b/models/actions/task.go @@ -21,7 +21,6 @@ import ( "gitea.dev/modules/timeutil" "gitea.dev/modules/util" - "google.golang.org/protobuf/types/known/timestamppb" "xorm.io/builder" ) @@ -68,10 +67,6 @@ func init() { db.RegisterModel(new(ActionTask)) } -func (task *ActionTask) Duration() time.Duration { - return calculateDuration(task.Started, task.Stopped, task.Status, task.Updated) -} - func (task *ActionTask) IsStopped() bool { return task.Stopped > 0 } @@ -484,6 +479,7 @@ func UpdateTaskByState(ctx context.Context, runnerID int64, state *runnerv1.Task return nil } + now := timeutil.TimeStampNow() // state.Result is not unspecified means the task is finished if state.Result != runnerv1.Result_RESULT_UNSPECIFIED { if task.Status == StatusCancelling { @@ -492,7 +488,7 @@ func UpdateTaskByState(ctx context.Context, runnerID int64, state *runnerv1.Task } else { task.Status = StatusFromResult(state.Result) } - task.Stopped = timeutil.TimeStamp(state.StoppedAt.AsTime().Unix()) + task.Stopped = now if err := UpdateTask(ctx, task, "status", "stopped"); err != nil { return err } @@ -506,7 +502,7 @@ func UpdateTaskByState(ctx context.Context, runnerID int64, state *runnerv1.Task } } else { // Force update ActionTask.Updated to avoid the task being judged as a zombie task - task.Updated = timeutil.TimeStampNow() + task.Updated = now if err := UpdateTask(ctx, task, "updated"); err != nil { return err } @@ -522,11 +518,13 @@ func UpdateTaskByState(ctx context.Context, runnerID int64, state *runnerv1.Task result = v.Result step.LogIndex = v.LogIndex step.LogLength = v.LogLength - step.Started = convertTimestamp(v.StartedAt) - step.Stopped = convertTimestamp(v.StoppedAt) + if step.Started == 0 && v.StartedAt != nil { + step.Started = now + } } if result != runnerv1.Result_RESULT_UNSPECIFIED { step.Status = StatusFromResult(result) + step.Stopped = util.IfZero(step.Stopped, now) } else if step.Started != 0 { step.Status = StatusRunning } @@ -638,13 +636,6 @@ func FindOldTasksToExpire(ctx context.Context, olderThan timeutil.TimeStamp, lim Find(&tasks) } -func convertTimestamp(timestamp *timestamppb.Timestamp) timeutil.TimeStamp { - if timestamp.GetSeconds() == 0 && timestamp.GetNanos() == 0 { - return timeutil.TimeStamp(0) - } - return timeutil.TimeStamp(timestamp.AsTime().Unix()) -} - func logFileName(repoFullName string, taskID int64) string { ret := fmt.Sprintf("%s/%02x/%d.log", repoFullName, taskID%256, taskID) diff --git a/models/actions/task_test.go b/models/actions/task_test.go index a1b10231870..0ee7e028657 100644 --- a/models/actions/task_test.go +++ b/models/actions/task_test.go @@ -380,14 +380,19 @@ func TestUpdateTaskByStateIsAtomic(t *testing.T) { task, job := newRunningTaskForCancelling(t, "atomic-report-job", true) require.NoError(t, db.Insert(t.Context(), &ActionTaskStep{TaskID: task.ID, RepoID: task.RepoID, Status: StatusRunning})) unittest.GetXORMEngine().AddHook(&failFirstStepWrite{}) - finalState := &runnerv1.TaskState{Id: task.ID, Result: runnerv1.Result_RESULT_SUCCESS, StoppedAt: timestamppb.Now()} + skewed := ×tamppb.Timestamp{Seconds: 1} + finalState := &runnerv1.TaskState{Id: task.ID, Result: runnerv1.Result_RESULT_SUCCESS, StoppedAt: skewed, Steps: []*runnerv1.StepState{{StartedAt: skewed}}} + before := timeutil.TimeStampNow() _, err := UpdateTaskByState(t.Context(), task.RunnerID, finalState) require.Error(t, err) assert.Equal(t, StatusRunning, unittest.AssertExistsAndLoadBean(t, &ActionTask{ID: task.ID}).Status) assert.Equal(t, StatusRunning, unittest.AssertExistsAndLoadBean(t, &ActionRunJob{ID: job.ID}).Status) _, err = UpdateTaskByState(t.Context(), task.RunnerID, finalState) require.NoError(t, err) - assert.Equal(t, StatusSuccess, unittest.AssertExistsAndLoadBean(t, &ActionRunJob{ID: job.ID}).Status) + gotJob := unittest.AssertExistsAndLoadBean(t, &ActionRunJob{ID: job.ID}) + assert.Equal(t, StatusSuccess, gotJob.Status) + assert.GreaterOrEqual(t, gotJob.Stopped, before) + assert.GreaterOrEqual(t, unittest.AssertExistsAndLoadBean(t, &ActionTaskStep{TaskID: task.ID}).Started, before) } // newRunningTaskForCancelling inserts a running run/job/task assigned to a fresh runner, diff --git a/routers/web/devtest/mock_actions.go b/routers/web/devtest/mock_actions.go index bf99f461bd6..dcdffd201fa 100644 --- a/routers/web/devtest/mock_actions.go +++ b/routers/web/devtest/mock_actions.go @@ -55,9 +55,8 @@ func generateMockStepsLog(logCur actions.LogCursor, opts generateMockStepsLogOpt logStr = strings.ReplaceAll(logStr, "{step}", strconv.Itoa(logCur.Step)) logStr = strings.ReplaceAll(logStr, "{cursor}", strconv.FormatInt(cur, 10)) stepsLog = append(stepsLog, &actions.ViewStepLog{ - Step: logCur.Step, - Cursor: cur, - Started: time.Now().Unix() - 1, + Step: logCur.Step, + Cursor: cur, Lines: []*actions.ViewStepLogLine{ {Index: cur, Message: logStr, Timestamp: float64(time.Now().UnixNano()) / float64(time.Second)}, }, diff --git a/routers/web/repo/actions/view.go b/routers/web/repo/actions/view.go index 687f0d07138..55163cc94ee 100644 --- a/routers/web/repo/actions/view.go +++ b/routers/web/repo/actions/view.go @@ -406,10 +406,9 @@ type ViewJobStep struct { } type ViewStepLog struct { - Step int `json:"step"` - Cursor int64 `json:"cursor"` - Lines []*ViewStepLogLine `json:"lines"` - Started int64 `json:"started"` + Step int `json:"step"` + Cursor int64 `json:"cursor"` + Lines []*ViewStepLogLine `json:"lines"` } type ViewStepLogLine struct { @@ -875,7 +874,6 @@ func convertToViewModel(ctx context.Context, locale translation.Locale, cursors Timestamp: float64(task.Updated.AsTime().UnixNano()) / float64(time.Second), }, }, - Started: int64(step.Started), }) } continue @@ -911,10 +909,9 @@ func convertToViewModel(ctx context.Context, locale translation.Locale, cursors } logs = append(logs, &ViewStepLog{ - Step: cursor.Step, - Cursor: cursor.Cursor + int64(len(logLines)), - Lines: logLines, - Started: int64(step.Started), + Step: cursor.Step, + Cursor: cursor.Cursor + int64(len(logLines)), + Lines: logLines, }) } diff --git a/web_src/js/components/ActionRunJobView.vue b/web_src/js/components/ActionRunJobView.vue index 6217db219e5..5d4087b3f6f 100644 --- a/web_src/js/components/ActionRunJobView.vue +++ b/web_src/js/components/ActionRunJobView.vue @@ -46,6 +46,7 @@ type JobStepState = { cursor: string|null, expanded: boolean, manuallyCollapsed: boolean, // whether the user manually collapsed the step, used to avoid auto-expanding it again + firstLogTime?: number, // the step's first log line time, what "Show seconds" counts from } // one ANSI renderer per step, so an unterminated color carries between that step's lines only @@ -81,7 +82,6 @@ type JobData = { stepsLog?: Array<{ step: number; cursor: string | null; - started: number; lines: LogLine[]; }>; }, @@ -355,9 +355,12 @@ async function loadJob() { // append logs to the UI for (const stepLogs of jobLogs) { + const stepState = currentJobStepsStates.value[stepLogs.step]; // save the cursor, it will be passed to backend next time - currentJobStepsStates.value[stepLogs.step].cursor = stepLogs.cursor; - appendLogs(stepLogs.step, stepLogs.started, stepLogs.lines); + stepState.cursor = stepLogs.cursor; + if (!stepLogs.lines.length) continue; + stepState.firstLogTime ??= stepLogs.lines[0].timestamp; + appendLogs(stepLogs.step, stepState.firstLogTime, stepLogs.lines); } // auto-scroll to the last log line of the last step