diff --git a/act/common/git/git.go b/act/common/git/git.go index 243aa5db..0ef1eab5 100644 --- a/act/common/git/git.go +++ b/act/common/git/git.go @@ -261,6 +261,10 @@ type NewGitCloneExecutorInput struct { // 0 for full clone. Depth int + // Quiet drops the informational clone line to debug level, for callers that log their own + // download summary (the setup section's action report). + Quiet bool + // For Gitea InsecureSkipTLS bool } @@ -347,7 +351,11 @@ func gitOptions(token string) (fetchOptions git.FetchOptions, pullOptions git.Pu func NewGitCloneExecutor(input NewGitCloneExecutorInput) common.Executor { return func(ctx context.Context) error { logger := common.Logger(ctx) - logger.Infof("git clone '%s' # ref=%s", input.URL, input.Ref) + if input.Quiet { + logger.Debugf("git clone '%s' # ref=%s", input.URL, input.Ref) + } else { + logger.Infof("git clone '%s' # ref=%s", input.URL, input.Ref) + } logger.Debugf(" cloning %s to %s", input.URL, input.Dir) defer AcquireCloneLock(input.Dir)() diff --git a/act/common/git/git_test.go b/act/common/git/git_test.go index 271080b7..02811acd 100644 --- a/act/common/git/git_test.go +++ b/act/common/git/git_test.go @@ -17,6 +17,10 @@ import ( "testing" "time" + "gitea.com/gitea/runner/act/common" + + log "github.com/sirupsen/logrus" + logrustest "github.com/sirupsen/logrus/hooks/test" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" ) @@ -404,6 +408,44 @@ func TestGitCloneExecutorOfflineMode(t *testing.T) { }) } +func TestGitCloneExecutorQuietDemotesCloneLine(t *testing.T) { + remoteDir := t.TempDir() + require.NoError(t, gitCmd("init", "--bare", "--initial-branch=main", remoteDir)) + workDir := t.TempDir() + require.NoError(t, gitCmd("clone", remoteDir, workDir)) + require.NoError(t, gitCmd("-C", workDir, "checkout", "-b", "main")) + require.NoError(t, gitCmd("-C", workDir, "commit", "--allow-empty", "-m", "initial")) + require.NoError(t, gitCmd("-C", workDir, "push", "-u", "origin", "main")) + + // Quiet callers report the download themselves, so the clone line must not reach the job log. + for name, quiet := range map[string]bool{"quiet": true, "not quiet": false} { + t.Run(name, func(t *testing.T) { + logger, hook := logrustest.NewNullLogger() + logger.SetLevel(log.InfoLevel) + ctx := common.WithLogger(context.Background(), logger.WithField("job", "j1")) + + require.NoError(t, NewGitCloneExecutor(NewGitCloneExecutorInput{ + URL: remoteDir, + Ref: "main", + Dir: t.TempDir(), + Quiet: quiet, + })(ctx)) + + var cloneLines int + for _, entry := range hook.AllEntries() { + if strings.HasPrefix(entry.Message, "git clone ") { + cloneLines++ + } + } + if quiet { + assert.Zero(t, cloneLines) + } else { + assert.Equal(t, 1, cloneLines) + } + }) + } +} + func TestGitCloneExecutorShallow(t *testing.T) { // Build a local "remote" with several commits on main plus a tag, so a full clone would pull noticeably more history than a shallow one. remoteDir := t.TempDir() diff --git a/act/runner/job_executor.go b/act/runner/job_executor.go index ed27f1c5..099362fb 100644 --- a/act/runner/job_executor.go +++ b/act/runner/job_executor.go @@ -71,9 +71,67 @@ func reportStepError(ctx context.Context, rc *RunContext, err error) { rc.markFailed() } +// actionPreparer is implemented by steps that download an action before they run, so the job +// executor can fetch all of them up front. +type actionPreparer interface { + prepareActionExecutor() common.Executor + actionDownloadInfo() (reference, sha string, ok bool) +} + +// printPrepareActions downloads every action the job uses before its first step runs and reports +// them as actions/runner's "Prepare all required actions" section does. The steps still call +// prepareActionExecutor themselves; it is a no-op once the action is resolved here. +func printPrepareActions(rc *RunContext, preparers []actionPreparer) common.Executor { + return func(ctx context.Context) error { + if len(preparers) == 0 { + return nil + } + + rawLogger := common.Logger(ctx).WithField(rawOutputField, true) + rawLogger.Infof("Prepare all required actions") + + for _, preparer := range preparers { + if err := preparer.prepareActionExecutor()(ctx); err != nil { + // No step has run yet, so the failure belongs to the job. + reportStepError(ctx, rc, err) + return err + } + reference, sha, ok := preparer.actionDownloadInfo() + if !ok { + continue + } + if sha == "" { + rawLogger.Infof("Download action repository '%s'", reference) + } else { + rawLogger.Infof("Download action repository '%s' (SHA:%s)", reference, sha) + } + } + return nil + } +} + +// printCompleteJobName closes the setup section the way actions/runner ends its "Set up job" step. +func printCompleteJobName(rc *RunContext) common.Executor { + return func(ctx context.Context) error { + // Name holds a matrix combination; JobName is the shared name GitHub reports. + name := rc.JobName + if name == "" { + name = rc.Name + } + if name == "" && rc.Run != nil { + name = rc.Run.JobID + } + common.Logger(ctx).WithField(rawOutputField, true).Infof("Complete job name: %s", name) + return nil + } +} + func newJobExecutor(info jobInfo, sf stepFactory, rc *RunContext) common.Executor { steps := make([]common.Executor, 0) preSteps := make([]common.Executor, 0) + // Collected separately: every action is downloaded before the first pre step runs. + stepPreSteps := make([]common.Executor, 0) + preparers := make([]actionPreparer, 0) var postExecutor common.Executor steps = append(steps, func(ctx context.Context) error { @@ -120,9 +178,13 @@ func newJobExecutor(info jobInfo, sf stepFactory, rc *RunContext) common.Executo return common.NewErrorExecutor(err) } + if preparer, ok := step.(actionPreparer); ok { + preparers = append(preparers, preparer) + } + stepIdx := stepModel.Number preExec := step.pre() - preSteps = append(preSteps, useStepLogger(rc, stepModel, stepStagePre, func(ctx context.Context) error { + stepPreSteps = append(stepPreSteps, useStepLogger(rc, stepModel, stepStagePre, func(ctx context.Context) error { rc.CurrentStepIndex = stepIdx preErr := preExec(ctx) if preErr != nil { @@ -164,6 +226,11 @@ func newJobExecutor(info jobInfo, sf stepFactory, rc *RunContext) common.Executo } } + // The setup section of the job log: download the actions, run the pre steps, then name the job. + preSteps = append(preSteps, printPrepareActions(rc, preparers)) + preSteps = append(preSteps, stepPreSteps...) + preSteps = append(preSteps, printCompleteJobName(rc)) + postExecutor = postExecutor.Finally(func(ctx context.Context) error { jobError := common.JobError(ctx) var err error diff --git a/act/runner/job_executor_test.go b/act/runner/job_executor_test.go index 4c1cf7f0..aa723721 100644 --- a/act/runner/job_executor_test.go +++ b/act/runner/job_executor_test.go @@ -24,6 +24,7 @@ import ( "gitea.com/gitea/runner/act/container" "gitea.com/gitea/runner/act/model" + log "github.com/sirupsen/logrus" logrustest "github.com/sirupsen/logrus/hooks/test" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/mock" @@ -111,6 +112,182 @@ func (sfm *stepFactoryMock) newStep(model *model.Step, rc *RunContext) (step, er return args.Get(0).(step), args.Error(1) } +// actionPreparerMock stands in for a step whose action is downloaded before the job's first step. +type actionPreparerMock struct { + reference string + sha string + ok bool + err error + prepared int +} + +func (apm *actionPreparerMock) prepareActionExecutor() common.Executor { + return func(context.Context) error { + apm.prepared++ + return apm.err + } +} + +func (apm *actionPreparerMock) actionDownloadInfo() (string, string, bool) { + return apm.reference, apm.sha, apm.ok +} + +func TestPrintPrepareActionsGolden(t *testing.T) { + buf := &bytes.Buffer{} + logger := log.New() + logger.SetOutput(buf) + logger.SetLevel(log.InfoLevel) + logger.SetFormatter(&jobLogFormatter{color: cyan}) + ctx := common.WithLogger(context.Background(), logger.WithFields(log.Fields{"job": "j1"})) + + preparers := []actionPreparer{ + &actionPreparerMock{reference: "actions/checkout@v7", sha: "9c091bb21b7c1c1d1991bb908d89e4e9dddfe3e0", ok: true}, + // A resolved commit is best effort; the ref alone is reported when it is unknown. + &actionPreparerMock{reference: "actions/setup-go@v6", ok: true}, + // A step that downloads nothing, such as the checkout of the workflow's own repository. + &actionPreparerMock{ok: false}, + } + require.NoError(t, printPrepareActions(&RunContext{}, preparers)(ctx)) + + want := strings.Join([]string{ + "[j1] | Prepare all required actions", + "[j1] | Download action repository 'actions/checkout@v7' (SHA:9c091bb21b7c1c1d1991bb908d89e4e9dddfe3e0)", + "[j1] | Download action repository 'actions/setup-go@v6'", + "", + }, "\n") + assert.Equal(t, want, buf.String()) +} + +func TestPrintPrepareActionsSkipsWithoutActions(t *testing.T) { + buf := &bytes.Buffer{} + logger := log.New() + logger.SetOutput(buf) + logger.SetFormatter(&jobLogFormatter{color: cyan}) + ctx := common.WithLogger(context.Background(), logger.WithFields(log.Fields{"job": "j1"})) + + require.NoError(t, printPrepareActions(&RunContext{}, nil)(ctx)) + + assert.Empty(t, buf.String()) +} + +func TestPrintPrepareActionsFailsJobOnDownloadError(t *testing.T) { + logger, _ := logrustest.NewNullLogger() + ctx := common.WithJobErrorContainer(common.WithLogger(context.Background(), logger.WithField("job", "j1"))) + + downloadErr := errors.New("failed to fetch \"actions/checkout\"") + rc := &RunContext{} + remaining := &actionPreparerMock{reference: "actions/setup-go@v6", ok: true} + + err := printPrepareActions(rc, []actionPreparer{ + &actionPreparerMock{err: downloadErr}, + remaining, + })(ctx) + + require.ErrorIs(t, err, downloadErr) + // No step has run yet, so the failure has to be recorded against the job itself. + assert.Equal(t, downloadErr, common.JobError(ctx)) + assert.True(t, rc.jobFailed) + assert.Zero(t, remaining.prepared) +} + +func TestPrintCompleteJobName(t *testing.T) { + for name, tt := range map[string]struct { + rc *RunContext + want string + }{ + "job name": {rc: &RunContext{JobName: "lint", Name: "lint-1"}, want: "lint"}, + "falls back to name": {rc: &RunContext{Name: "lint-1"}, want: "lint-1"}, + "falls back to jobID": {rc: &RunContext{Run: &model.Run{JobID: "lint"}}, want: "lint"}, + } { + t.Run(name, func(t *testing.T) { + buf := &bytes.Buffer{} + logger := log.New() + logger.SetOutput(buf) + logger.SetFormatter(&jobLogFormatter{color: cyan}) + ctx := common.WithLogger(context.Background(), logger.WithFields(log.Fields{"job": "j1"})) + + require.NoError(t, printCompleteJobName(tt.rc)(ctx)) + + assert.Equal(t, "[j1] | Complete job name: "+tt.want+"\n", buf.String()) + }) + } +} + +// actionStepMock is a step whose action has to be downloaded before it can run. +type actionStepMock struct { + *stepMock + *actionPreparerMock +} + +// TestNewJobExecutorDownloadsAllActionsBeforeTheFirstStep pins the shape of the setup section: +// every action is downloaded before any step runs, and the job name closes the section. A pre +// step that downloaded its own action would leave the log interleaved with the downloads. +func TestNewJobExecutorDownloadsAllActionsBeforeTheFirstStep(t *testing.T) { + ctx := common.WithJobErrorContainer(context.Background()) + jim := &jobInfoMock{} + sfm := &stepFactoryMock{} + rc := &RunContext{ + JobContainer: &jobContainerMock{}, + Run: &model.Run{ + JobID: "test", + Workflow: &model.Workflow{ + Jobs: map[string]*model.Job{"test": {}}, + }, + }, + Config: &Config{}, + } + rc.ExprEval = rc.NewExpressionEvaluator(ctx) + + steps := []*model.Step{{ID: "1"}, {ID: "2"}} + executorOrder := make([]string, 0) + + jim.On("steps").Return(steps) + jim.On("matrix").Return(map[string]any{}) + jim.On("startContainer").Return(func(context.Context) error { return nil }) + jim.On("stopContainer").Return(func(context.Context) error { return nil }) + jim.On("closeContainer").Return(func(context.Context) error { return nil }) + jim.On("interpolateOutputs").Return(func(context.Context) error { return nil }) + jim.On("result", "success") + + for _, stepModel := range steps { + sm := &stepMock{} + apm := &actionPreparerMock{reference: "actions/checkout@v" + stepModel.ID, ok: true} + sfm.On("newStep", stepModel, rc).Return(&actionStepMock{stepMock: sm, actionPreparerMock: apm}, nil) + + sm.On("pre").Return(func(context.Context) error { + executorOrder = append(executorOrder, "pre"+stepModel.ID) + return nil + }) + sm.On("main").Return(func(context.Context) error { + executorOrder = append(executorOrder, "step"+stepModel.ID) + return nil + }) + sm.On("post").Return(func(context.Context) error { return nil }) + + defer sm.AssertExpectations(t) + } + + logger, hook := logrustest.NewNullLogger() + err := newJobExecutor(jim, sfm, rc)(common.WithLogger(ctx, logger.WithField("job", "test"))) + require.NoError(t, err) + + assert.Equal(t, []string{"pre1", "pre2", "step1", "step2"}, executorOrder) + + setup := make([]string, 0) + for _, entry := range hook.AllEntries() { + if strings.HasPrefix(entry.Message, "Prepare all required actions") || strings.HasPrefix(entry.Message, "Download action") || + strings.HasPrefix(entry.Message, "Complete job name") { + setup = append(setup, entry.Message) + } + } + assert.Equal(t, []string{ + "Prepare all required actions", + "Download action repository 'actions/checkout@v1'", + "Download action repository 'actions/checkout@v2'", + "Complete job name: test", + }, setup) +} + func TestNewJobExecutor(t *testing.T) { table := []struct { name string diff --git a/act/runner/step.go b/act/runner/step.go index c67f5ba7..01a44108 100644 --- a/act/runner/step.go +++ b/act/runner/step.go @@ -107,7 +107,13 @@ func runStepExecutor(step step, stage stepStage, executor common.Executor) commo if strings.Contains(stepString, "::add-mask::") { stepString = "add-mask command" } - logger.Infof("Run %s %s", stage, stepString) + if stage == stepStageMain { + // Main steps print their own raw "Run