77 "context"
88 "errors"
99 "fmt"
10+ "time"
1011
1112 actions_model "code.gitea.io/gitea/models/actions"
1213 "code.gitea.io/gitea/models/db"
@@ -202,6 +203,9 @@ func checkJobsOfRun(ctx context.Context, run *actions_model.ActionRun) (jobs, up
202203 if err != nil {
203204 return nil , nil , err
204205 }
206+
207+ log .Debug ("Checking %d jobs for run %d (status: %s)" , len (jobs ), run .ID , run .Status )
208+
205209 vars , err := actions_model .GetVariablesOfRun (ctx , run )
206210 if err != nil {
207211 return nil , nil , err
@@ -213,14 +217,18 @@ func checkJobsOfRun(ctx context.Context, run *actions_model.ActionRun) (jobs, up
213217 }
214218
215219 updates := newJobStatusResolver (jobs , vars ).Resolve (ctx )
220+ log .Debug ("Job status resolver returned %d job status updates for run %d" , len (updates ), run .ID )
221+
216222 for _ , job := range jobs {
217223 if status , ok := updates [job .ID ]; ok {
224+ oldStatus := job .Status
218225 job .Status = status
219226 if n , err := actions_model .UpdateRunJob (ctx , job , builder.Eq {"status" : actions_model .StatusBlocked }, "status" ); err != nil {
220227 return err
221228 } else if n != 1 {
222229 return fmt .Errorf ("no affected for updating blocked job %v" , job .ID )
223230 }
231+ log .Info ("Job %d (JobID: %s) status updated: %s -> %s" , job .ID , job .JobID , oldStatus , status )
224232 updatedJobs = append (updatedJobs , job )
225233 }
226234 }
@@ -229,6 +237,20 @@ func checkJobsOfRun(ctx context.Context, run *actions_model.ActionRun) (jobs, up
229237 return nil , nil , err
230238 }
231239
240+ // Reload jobs from the database to pick up any newly created matrix jobs
241+ oldJobCount := len (jobs )
242+ jobs , err = db .Find [actions_model.ActionRunJob ](ctx , actions_model.FindRunJobOptions {RunID : run .ID })
243+ if err != nil {
244+ return nil , nil , err
245+ }
246+
247+ if len (jobs ) > oldJobCount {
248+ log .Info ("Matrix re-evaluation created %d new jobs for run %d (was %d, now %d)" ,
249+ len (jobs )- oldJobCount , run .ID , oldJobCount , len (jobs ))
250+ }
251+
252+ log .Debug ("Job check completed for run %d: %d jobs updated, %d total jobs" , run .ID , len (updatedJobs ), len (jobs ))
253+
232254 return jobs , updatedJobs , nil
233255}
234256
@@ -313,47 +335,102 @@ func (r *jobStatusResolver) resolveJobHasIfCondition(actionRunJob *actions_model
313335
314336func (r * jobStatusResolver ) resolve (ctx context.Context ) map [int64 ]actions_model.Status {
315337 ret := map [int64 ]actions_model.Status {}
338+ resolveMetrics := struct {
339+ totalBlocked int
340+ matrixReevaluated int
341+ concurrencyUpdated int
342+ jobsStarted int
343+ jobsSkipped int
344+ }{}
345+
316346 for id , status := range r .statuses {
317347 actionRunJob := r .jobMap [id ]
318348 if status != actions_model .StatusBlocked {
319349 continue
320350 }
351+
352+ resolveMetrics .totalBlocked ++
353+ log .Debug ("Resolving blocked job %d (JobID: %s, RunID: %d)" , id , actionRunJob .JobID , actionRunJob .RunID )
354+
321355 allDone , allSucceed := r .resolveCheckNeeds (id )
322356 if ! allDone {
357+ log .Debug ("Job %d: not all dependencies completed yet" , id )
323358 continue
324359 }
325360
361+ log .Debug ("Job %d: all dependencies completed (allSucceed: %v), checking matrix re-evaluation" , id , allSucceed )
362+
363+ // Try to re-evaluate the matrix with job outputs if it depends on them
364+ startTime := time .Now ()
365+ newMatrixJobs , err := ReEvaluateMatrixForJobWithNeeds (ctx , actionRunJob , r .vars )
366+ duration := time .Since (startTime ).Milliseconds ()
367+
368+ if err != nil {
369+ log .Error ("Matrix re-evaluation error for job %d (JobID: %s): %v (duration: %dms)" , id , actionRunJob .JobID , err , duration )
370+ continue
371+ }
372+
373+ // If new matrix jobs were created, add them to the resolver and continue
374+ if len (newMatrixJobs ) > 0 {
375+ resolveMetrics .matrixReevaluated ++
376+ log .Info ("Matrix re-evaluation succeeded for job %d (JobID: %s): created %d new jobs (duration: %dms)" ,
377+ id , actionRunJob .JobID , len (newMatrixJobs ), duration )
378+ // The new jobs will be picked up in the next resolution iteration
379+ continue
380+ }
381+
382+ log .Debug ("Job %d: no matrix re-evaluation needed or result is empty" , id )
383+
326384 // update concurrency and check whether the job can run now
327- err : = updateConcurrencyEvaluationForJobWithNeeds (ctx , actionRunJob , r .vars )
385+ err = updateConcurrencyEvaluationForJobWithNeeds (ctx , actionRunJob , r .vars )
328386 if err != nil {
329387 // The err can be caused by different cases: database error, or syntax error, or the needed jobs haven't completed
330388 // At the moment there is no way to distinguish them.
331389 // Actually, for most cases, the error is caused by "syntax error" / "the needed jobs haven't completed (skipped?)"
332390 // TODO: if workflow or concurrency expression has syntax error, there should be a user error message, need to show it to end users
333- log .Debug ("updateConcurrencyEvaluationForJobWithNeeds failed, this job will stay blocked: job: %d, err : %v" , id , err )
391+ log .Debug ("Concurrency evaluation failed for job %d (JobID: %s) : %v (job will stay blocked) " , id , actionRunJob . JobID , err )
334392 continue
335393 }
336394
395+ resolveMetrics .concurrencyUpdated ++
396+
337397 shouldStartJob := true
338398 if ! allSucceed {
339399 // Not all dependent jobs completed successfully:
340400 // * if the job has "if" condition, it can be started, then the act_runner will evaluate the "if" condition.
341401 // * otherwise, the job should be skipped.
342402 shouldStartJob = r .resolveJobHasIfCondition (actionRunJob )
403+ log .Debug ("Job %d: not all dependencies succeeded. Has if-condition: %v, should start: %v" , id , shouldStartJob , shouldStartJob )
343404 }
344405
345406 newStatus := util .Iif (shouldStartJob , actions_model .StatusWaiting , actions_model .StatusSkipped )
346407 if newStatus == actions_model .StatusWaiting {
347408 newStatus , err = PrepareToStartJobWithConcurrency (ctx , actionRunJob )
348409 if err != nil {
349- log .Error ("ShouldBlockJobByConcurrency failed, this job will stay blocked: job: %d, err : %v" , id , err )
410+ log .Error ("Concurrency check failed for job %d (JobID: %s) : %v (job will stay blocked) " , id , actionRunJob . JobID , err )
350411 }
351412 }
352413
353414 if newStatus != actions_model .StatusBlocked {
354415 ret [id ] = newStatus
416+ switch newStatus {
417+ case actions_model .StatusWaiting :
418+ resolveMetrics .jobsStarted ++
419+ log .Info ("Job %d (JobID: %s) transitioned to StatusWaiting" , id , actionRunJob .JobID )
420+ case actions_model .StatusSkipped :
421+ resolveMetrics .jobsSkipped ++
422+ log .Info ("Job %d (JobID: %s) transitioned to StatusSkipped" , id , actionRunJob .JobID )
423+ }
355424 }
356425 }
426+
427+ // Log resolution metrics summary
428+ if resolveMetrics .totalBlocked > 0 {
429+ log .Debug ("Job resolution summary: total_blocked=%d, matrix_reevaluated=%d, concurrency_updated=%d, jobs_started=%d, jobs_skipped=%d" ,
430+ resolveMetrics .totalBlocked , resolveMetrics .matrixReevaluated , resolveMetrics .concurrencyUpdated ,
431+ resolveMetrics .jobsStarted , resolveMetrics .jobsSkipped )
432+ }
433+
357434 return ret
358435}
359436
0 commit comments