diff options
| author | Björn Brauer <bjoern.brauer@new-work.se> | 2022-06-17 17:55:21 +0200 |
|---|---|---|
| committer | GitHub <noreply@github.com> | 2022-06-17 17:55:21 +0200 |
| commit | 4391a10d5a013afb3a4cbc1640eb745132593d7a (patch) | |
| tree | bd8dd65ba3565512fcad8437a9093a06e350b588 | |
| parent | fix: allow TimeoutMinutes to be expression (#1217) (diff) | |
| download | forgejo-act-4391a10d5a013afb3a4cbc1640eb745132593d7a.tar.xz forgejo-act-4391a10d5a013afb3a4cbc1640eb745132593d7a.zip | |
Improve logging (#1171)
* feat: use logger from context wherever possible
Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
* feat: add step/job id and results to json logs
Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
* test: value to be masked should not be hard-coded in the action
Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
* fix: replace values following ::add-mask:: in evaluated strings
Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
* feat: [DEBUG] identifier for debug logs to distinguish them
Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
* feat: replace logger with step logger
The container gets injected a job logger, but during the time that steps
are run, we want to use the step logger.
This commit wraps pre/main/post steps in an executor that replaces the
job logger with a step logger.
Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
* feat: add pre/post stage identifier fields to json log output
Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
* feat: add job/step result status to skipped steps/jobs
Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
Co-authored-by: mergify[bot] <37929162+mergify[bot]@users.noreply.github.com>
35 files changed, 363 insertions, 292 deletions
diff --git a/pkg/artifacts/server.go b/pkg/artifacts/server.go index 2d8fe9b..c39c921 100644 --- a/pkg/artifacts/server.go +++ b/pkg/artifacts/server.go @@ -15,7 +15,6 @@ import ( "github.com/julienschmidt/httprouter" "github.com/nektos/act/pkg/common" - log "github.com/sirupsen/logrus" ) type FileContainerResourceURL struct { @@ -241,6 +240,7 @@ func downloads(router *httprouter.Router, fsys fs.FS) { func Serve(ctx context.Context, artifactPath string, port string) context.CancelFunc { serverContext, cancel := context.WithCancel(ctx) + logger := common.Logger(serverContext) if artifactPath == "" { return cancel @@ -248,7 +248,7 @@ func Serve(ctx context.Context, artifactPath string, port string) context.Cancel router := httprouter.New() - log.Debugf("Artifacts base path '%s'", artifactPath) + logger.Debugf("Artifacts base path '%s'", artifactPath) fs := os.DirFS(artifactPath) uploads(router, MkdirFsImpl{artifactPath, fs}) downloads(router, fs) @@ -258,9 +258,9 @@ func Serve(ctx context.Context, artifactPath string, port string) context.Cancel // run server go func() { - log.Infof("Start server on http://%s:%s", ip, port) + logger.Infof("Start server on http://%s:%s", ip, port) if err := server.ListenAndServe(); err != nil && err != http.ErrServerClosed { - log.Fatal(err) + logger.Fatal(err) } }() @@ -269,7 +269,7 @@ func Serve(ctx context.Context, artifactPath string, port string) context.Cancel <-serverContext.Done() if err := server.Shutdown(ctx); err != nil { - log.Errorf("Failed shutdown gracefully - force shutdown: %v", err) + logger.Errorf("Failed shutdown gracefully - force shutdown: %v", err) server.Close() } }() diff --git a/pkg/common/executor.go b/pkg/common/executor.go index fb76d0b..c5b05f3 100644 --- a/pkg/common/executor.go +++ b/pkg/common/executor.go @@ -3,8 +3,6 @@ package common import ( "context" "fmt" - - log "github.com/sirupsen/logrus" ) // Warning that implements `error` but safe to ignore @@ -132,7 +130,7 @@ func (e Executor) Then(then Executor) Executor { if err != nil { switch err.(type) { case Warning: - log.Warning(err.Error()) + Logger(ctx).Warning(err.Error()) default: return err } diff --git a/pkg/common/git/git.go b/pkg/common/git/git.go index 51c8072..38f8f71 100644 --- a/pkg/common/git/git.go +++ b/pkg/common/git/git.go @@ -54,7 +54,8 @@ func (e *Error) Commit() string { } // FindGitRevision get the current git revision -func FindGitRevision(file string) (shortSha string, sha string, err error) { +func FindGitRevision(ctx context.Context, file string) (shortSha string, sha string, err error) { + logger := common.Logger(ctx) gitDir, err := findGitDirectory(file) if err != nil { return "", "", err @@ -77,24 +78,25 @@ func FindGitRevision(file string) (shortSha string, sha string, err error) { refBuf = []byte(ref) } - log.Debugf("Found revision: %s", refBuf) + logger.Debugf("Found revision: %s", refBuf) return string(refBuf[:7]), strings.TrimSpace(string(refBuf)), nil } // FindGitRef get the current git ref -func FindGitRef(file string) (string, error) { +func FindGitRef(ctx context.Context, file string) (string, error) { + logger := common.Logger(ctx) gitDir, err := findGitDirectory(file) if err != nil { return "", err } - log.Debugf("Loading revision from git directory '%s'", gitDir) + logger.Debugf("Loading revision from git directory '%s'", gitDir) - _, ref, err := FindGitRevision(file) + _, ref, err := FindGitRevision(ctx, file) if err != nil { return "", err } - log.Debugf("HEAD points to '%s'", ref) + logger.Debugf("HEAD points to '%s'", ref) // Prefer the git library to iterate over the references and find a matching tag or branch. var refTag = "" @@ -108,7 +110,7 @@ func FindGitRef(file string) (string, error) { if r == nil || err != nil { break } - // log.Debugf("Reference: name=%s sha=%s", r.Name().String(), r.Hash().String()) + // logger.Debugf("Reference: name=%s sha=%s", r.Name().String(), r.Hash().String()) if r.Hash().String() == ref { if r.Name().IsTag() { refTag = r.Name().String() @@ -131,15 +133,15 @@ func FindGitRef(file string) (string, error) { // If the above doesn't work, fall back to the old way // try tags first - tag, err := findGitPrettyRef(ref, gitDir, "refs/tags") + tag, err := findGitPrettyRef(ctx, ref, gitDir, "refs/tags") if err != nil || tag != "" { return tag, err } // and then branches - return findGitPrettyRef(ref, gitDir, "refs/heads") + return findGitPrettyRef(ctx, ref, gitDir, "refs/heads") } -func findGitPrettyRef(head, root, sub string) (string, error) { +func findGitPrettyRef(ctx context.Context, head, root, sub string) (string, error) { var name string var err = filepath.Walk(filepath.Join(root, sub), func(path string, info os.FileInfo, err error) error { if err != nil { @@ -156,7 +158,7 @@ func findGitPrettyRef(head, root, sub string) (string, error) { if head == pointsTo { // On Windows paths are separated with backslash character so they should be replaced to provide proper git refs format name = strings.TrimPrefix(strings.ReplaceAll(strings.Replace(path, root, "", 1), `\`, `/`), "/") - log.Debugf("HEAD matches %s", name) + common.Logger(ctx).Debugf("HEAD matches %s", name) } return nil }) @@ -164,12 +166,12 @@ func findGitPrettyRef(head, root, sub string) (string, error) { } // FindGithubRepo get the repo -func FindGithubRepo(file, githubInstance, remoteName string) (string, error) { +func FindGithubRepo(ctx context.Context, file, githubInstance, remoteName string) (string, error) { if remoteName == "" { remoteName = "origin" } - url, err := findGitRemoteURL(file, remoteName) + url, err := findGitRemoteURL(ctx, file, remoteName) if err != nil { return "", err } @@ -177,12 +179,12 @@ func FindGithubRepo(file, githubInstance, remoteName string) (string, error) { return slug, err } -func findGitRemoteURL(file, remoteName string) (string, error) { +func findGitRemoteURL(ctx context.Context, file, remoteName string) (string, error) { gitDir, err := findGitDirectory(file) if err != nil { return "", err } - log.Debugf("Loading slug from git directory '%s'", gitDir) + common.Logger(ctx).Debugf("Loading slug from git directory '%s'", gitDir) gitconfig, err := ini.InsensitiveLoad(fmt.Sprintf("%s/config", gitDir)) if err != nil { diff --git a/pkg/common/git/git_test.go b/pkg/common/git/git_test.go index 932eb14..067744d 100644 --- a/pkg/common/git/git_test.go +++ b/pkg/common/git/git_test.go @@ -86,7 +86,7 @@ func TestFindGitRemoteURL(t *testing.T) { err = gitCmd("config", "-f", fmt.Sprintf("%s/.git/config", basedir), "--add", "remote.origin.url", remoteURL) assert.NoError(err) - u, err := findGitRemoteURL(basedir, "origin") + u, err := findGitRemoteURL(context.Background(), basedir, "origin") assert.NoError(err) assert.Equal(remoteURL, u) } @@ -165,7 +165,7 @@ func TestGitFindRef(t *testing.T) { require.NoError(t, gitCmd("-C", dir, "init", "--initial-branch=master")) require.NoError(t, cleanGitHooks(dir)) tt.Prepare(t, dir) - ref, err := FindGitRef(dir) + ref, err := FindGitRef(context.Background(), dir) tt.Assert(t, ref, err) }) } diff --git a/pkg/container/docker_auth.go b/pkg/container/docker_auth.go index c470039..7d2fc4a 100644 --- a/pkg/container/docker_auth.go +++ b/pkg/container/docker_auth.go @@ -1,18 +1,20 @@ package container import ( + "context" "strings" "github.com/docker/cli/cli/config" "github.com/docker/cli/cli/config/credentials" "github.com/docker/docker/api/types" - log "github.com/sirupsen/logrus" + "github.com/nektos/act/pkg/common" ) -func LoadDockerAuthConfig(image string) (types.AuthConfig, error) { +func LoadDockerAuthConfig(ctx context.Context, image string) (types.AuthConfig, error) { + logger := common.Logger(ctx) config, err := config.Load(config.Dir()) if err != nil { - log.Warnf("Could not load docker config: %v", err) + logger.Warnf("Could not load docker config: %v", err) return types.AuthConfig{}, err } @@ -28,7 +30,7 @@ func LoadDockerAuthConfig(image string) (types.AuthConfig, error) { authConfig, err := config.GetAuthConfig(hostName) if err != nil { - log.Warnf("Could not get auth config from docker config: %v", err) + logger.Warnf("Could not get auth config from docker config: %v", err) return types.AuthConfig{}, err } diff --git a/pkg/container/docker_build.go b/pkg/container/docker_build.go index aaed140..17e2c7b 100644 --- a/pkg/container/docker_build.go +++ b/pkg/container/docker_build.go @@ -12,7 +12,6 @@ import ( // github.com/docker/docker/builder/dockerignore is deprecated "github.com/moby/buildkit/frontend/dockerfile/dockerignore" - log "github.com/sirupsen/logrus" "github.com/nektos/act/pkg/common" ) @@ -56,7 +55,7 @@ func NewDockerBuildExecutor(input NewDockerBuildExecutorInput) common.Executor { if input.Container != nil { buildContext, err = input.Container.GetContainerArchive(ctx, input.ContextDir+"/.") } else { - buildContext, err = createBuildContext(input.ContextDir, "Dockerfile") + buildContext, err = createBuildContext(ctx, input.ContextDir, "Dockerfile") } if err != nil { return err @@ -74,8 +73,8 @@ func NewDockerBuildExecutor(input NewDockerBuildExecutorInput) common.Executor { return nil } } -func createBuildContext(contextDir string, relDockerfile string) (io.ReadCloser, error) { - log.Debugf("Creating archive for build context dir '%s' with relative dockerfile '%s'", contextDir, relDockerfile) +func createBuildContext(ctx context.Context, contextDir string, relDockerfile string) (io.ReadCloser, error) { + common.Logger(ctx).Debugf("Creating archive for build context dir '%s' with relative dockerfile '%s'", contextDir, relDockerfile) // And canonicalize dockerfile name to a platform-independent one relDockerfile = archive.CanonicalTarNameForPath(relDockerfile) diff --git a/pkg/container/docker_pull.go b/pkg/container/docker_pull.go index 804f768..1eb04e1 100644 --- a/pkg/container/docker_pull.go +++ b/pkg/container/docker_pull.go @@ -8,7 +8,6 @@ import ( "github.com/docker/distribution/reference" "github.com/docker/docker/api/types" - log "github.com/sirupsen/logrus" "github.com/nektos/act/pkg/common" ) @@ -35,7 +34,7 @@ func NewDockerPullExecutor(input NewDockerPullExecutorInput) common.Executor { pull := input.ForcePull if !pull { imageExists, err := ImageExistsLocally(ctx, input.Image, input.Platform) - log.Debugf("Image exists? %v", imageExists) + logger.Debugf("Image exists? %v", imageExists) if err != nil { return fmt.Errorf("unable to determine if image already exists for image '%s' (%s): %w", input.Image, input.Platform, err) } @@ -49,7 +48,7 @@ func NewDockerPullExecutor(input NewDockerPullExecutorInput) common.Executor { return nil } - imageRef := cleanImage(input.Image) + imageRef := cleanImage(ctx, input.Image) logger.Debugf("pulling image '%v' (%s)", imageRef, input.Platform) cli, err := GetDockerClient(ctx) @@ -94,7 +93,7 @@ func getImagePullOptions(ctx context.Context, input NewDockerPullExecutorInput) imagePullOptions.RegistryAuth = base64.URLEncoding.EncodeToString(encodedJSON) } else { - authConfig, err := LoadDockerAuthConfig(input.Image) + authConfig, err := LoadDockerAuthConfig(ctx, input.Image) if err != nil { return imagePullOptions, err } @@ -113,10 +112,10 @@ func getImagePullOptions(ctx context.Context, input NewDockerPullExecutorInput) return imagePullOptions, nil } -func cleanImage(image string) string { +func cleanImage(ctx context.Context, image string) string { ref, err := reference.ParseAnyReference(image) if err != nil { - log.Error(err) + common.Logger(ctx).Error(err) return "" } diff --git a/pkg/container/docker_pull_test.go b/pkg/container/docker_pull_test.go index fa9705a..bfbe89d 100644 --- a/pkg/container/docker_pull_test.go +++ b/pkg/container/docker_pull_test.go @@ -29,7 +29,7 @@ func TestCleanImage(t *testing.T) { } for _, table := range tables { - imageOut := cleanImage(table.imageIn) + imageOut := cleanImage(context.Background(), table.imageIn) assert.Equal(t, table.imageOut, imageOut) } } diff --git a/pkg/container/docker_run.go b/pkg/container/docker_run.go index 29ac7ff..22c2008 100644 --- a/pkg/container/docker_run.go +++ b/pkg/container/docker_run.go @@ -28,7 +28,6 @@ import ( specs "github.com/opencontainers/image-spec/specs-go/v1" "github.com/Masterminds/semver" - log "github.com/sirupsen/logrus" "golang.org/x/term" "github.com/nektos/act/pkg/common" @@ -634,7 +633,7 @@ func (cr *containerReference) copyDir(dstPath string, srcPath string, useGitIgno if err != nil { return err } - log.Debugf("Writing tarball %s from %s", tarFile.Name(), srcPath) + logger.Debugf("Writing tarball %s from %s", tarFile.Name(), srcPath) defer func(tarFile *os.File) { name := tarFile.Name() err := tarFile.Close() @@ -652,13 +651,13 @@ func (cr *containerReference) copyDir(dstPath string, srcPath string, useGitIgno if !strings.HasSuffix(srcPrefix, string(filepath.Separator)) { srcPrefix += string(filepath.Separator) } - log.Debugf("Stripping prefix:%s src:%s", srcPrefix, srcPath) + logger.Debugf("Stripping prefix:%s src:%s", srcPrefix, srcPath) var ignorer gitignore.Matcher if useGitIgnore { ps, err := gitignore.ReadPatterns(polyfill.New(osfs.New(srcPath)), nil) if err != nil { - log.Debugf("Error loading .gitignore: %v", err) + logger.Debugf("Error loading .gitignore: %v", err) } ignorer = gitignore.NewMatcher(ps) @@ -701,7 +700,7 @@ func (cr *containerReference) copyContent(dstPath string, files ...*FileEntry) c var buf bytes.Buffer tw := tar.NewWriter(&buf) for _, file := range files { - log.Debugf("Writing entry to tarball %s len:%d", file.Name, len(file.Body)) + logger.Debugf("Writing entry to tarball %s len:%d", file.Name, len(file.Body)) hdr := &tar.Header{ Name: file.Name, Mode: file.Mode, diff --git a/pkg/model/github_context.go b/pkg/model/github_context.go index de8b0f8..577cab5 100644 --- a/pkg/model/github_context.go +++ b/pkg/model/github_context.go @@ -1,11 +1,11 @@ package model import ( + "context" "fmt" + "github.com/nektos/act/pkg/common" "github.com/nektos/act/pkg/common/git" - - log "github.com/sirupsen/logrus" ) type GithubContext struct { @@ -63,7 +63,7 @@ func nestedMapLookup(m map[string]interface{}, ks ...string) (rval interface{}) } } -func withDefaultBranch(b string, event map[string]interface{}) map[string]interface{} { +func withDefaultBranch(ctx context.Context, b string, event map[string]interface{}) map[string]interface{} { repoI, ok := event["repository"] if !ok { repoI = make(map[string]interface{}) @@ -71,7 +71,7 @@ func withDefaultBranch(b string, event map[string]interface{}) map[string]interf repo, ok := repoI.(map[string]interface{}) if !ok { - log.Warnf("unable to set default branch to %v", b) + common.Logger(ctx).Warnf("unable to set default branch to %v", b) return event } @@ -89,7 +89,8 @@ func withDefaultBranch(b string, event map[string]interface{}) map[string]interf var findGitRef = git.FindGitRef var findGitRevision = git.FindGitRevision -func (ghc *GithubContext) SetRefAndSha(defaultBranch string, repoPath string) { +func (ghc *GithubContext) SetRefAndSha(ctx context.Context, defaultBranch string, repoPath string) { + logger := common.Logger(ctx) // https://docs.github.com/en/actions/learn-github-actions/events-that-trigger-workflows // https://docs.github.com/en/developers/webhooks-and-events/webhooks/webhook-events-and-payloads switch ghc.EventName { @@ -113,19 +114,19 @@ func (ghc *GithubContext) SetRefAndSha(defaultBranch string, repoPath string) { } if ghc.Ref == "" { - ref, err := findGitRef(repoPath) + ref, err := findGitRef(ctx, repoPath) if err != nil { - log.Warningf("unable to get git ref: %v", err) + logger.Warningf("unable to get git ref: %v", err) } else { - log.Debugf("using github ref: %s", ref) + logger.Debugf("using github ref: %s", ref) ghc.Ref = ref } // set the branch in the event data if defaultBranch != "" { - ghc.Event = withDefaultBranch(defaultBranch, ghc.Event) + ghc.Event = withDefaultBranch(ctx, defaultBranch, ghc.Event) } else { - ghc.Event = withDefaultBranch("master", ghc.Event) + ghc.Event = withDefaultBranch(ctx, "master", ghc.Event) } if ghc.Ref == "" { @@ -134,9 +135,9 @@ func (ghc *GithubContext) SetRefAndSha(defaultBranch string, repoPath string) { } if ghc.Sha == "" { - _, sha, err := findGitRevision(repoPath) + _, sha, err := findGitRevision(ctx, repoPath) if err != nil { - log.Warningf("unable to get git revision: %v", err) + logger.Warningf("unable to get git revision: %v", err) } else { ghc.Sha = sha } diff --git a/pkg/model/github_context_test.go b/pkg/model/github_context_test.go index c3c8b56..f321f53 100644 --- a/pkg/model/github_context_test.go +++ b/pkg/model/github_context_test.go @@ -1,6 +1,7 @@ package model import ( + "context" "fmt" "testing" @@ -16,11 +17,11 @@ func TestSetRefAndSha(t *testing.T) { defer func() { findGitRef = oldFindGitRef }() defer func() { findGitRevision = oldFindGitRevision }() - findGitRef = func(file string) (string, error) { + findGitRef = func(ctx context.Context, file string) (string, error) { return "refs/heads/master", nil } - findGitRevision = func(file string) (string, string, error) { + findGitRevision = func(ctx context.Context, file string) (string, string, error) { return "", "1234fakesha", nil } @@ -107,7 +108,7 @@ func TestSetRefAndSha(t *testing.T) { Event: table.event, } - ghc.SetRefAndSha("main", "/some/dir") + ghc.SetRefAndSha(context.Background(), "main", "/some/dir") assert.Equal(t, table.ref, ghc.Ref) assert.Equal(t, table.sha, ghc.Sha) @@ -115,7 +116,7 @@ func TestSetRefAndSha(t *testing.T) { } t.Run("no-default-branch", func(t *testing.T) { - findGitRef = func(file string) (string, error) { + findGitRef = func(ctx context.Context, file string) (string, error) { return "", fmt.Errorf("no default branch") } @@ -124,7 +125,7 @@ func TestSetRefAndSha(t *testing.T) { Event: map[string]interface{}{}, } - ghc.SetRefAndSha("", "/some/dir") + ghc.SetRefAndSha(context.Background(), "", "/some/dir") assert.Equal(t, "master", ghc.Ref) assert.Equal(t, "1234fakesha", ghc.Sha) diff --git a/pkg/runner/action.go b/pkg/runner/action.go index fca55aa..72970f4 100644 --- a/pkg/runner/action.go +++ b/pkg/runner/action.go @@ -17,18 +17,17 @@ import ( "github.com/nektos/act/pkg/common" "github.com/nektos/act/pkg/container" "github.com/nektos/act/pkg/model" - log "github.com/sirupsen/logrus" ) type actionStep interface { step getActionModel() *model.Action - getCompositeRunContext() *RunContext + getCompositeRunContext(context.Context) *RunContext getCompositeSteps() *compositeSteps } -type readAction func(step *model.Step, actionDir string, actionPath string, readFile actionYamlReader, writeFile fileWriter) (*model.Action, error) +type readAction func(ctx context.Context, step *model.Step, actionDir string, actionPath string, readFile actionYamlReader, writeFile fileWriter) (*model.Action, error) type actionYamlReader func(filename string) (io.Reader, io.Closer, error) type fileWriter func(filename string, data []byte, perm fs.FileMode) error @@ -38,7 +37,8 @@ type runAction func(step actionStep, actionDir string, remoteAction *remoteActio //go:embed res/trampoline.js var trampoline embed.FS -func readActionImpl(step *model.Step, actionDir string, actionPath string, readFile actionYamlReader, writeFile fileWriter) (*model.Action, error) { +func readActionImpl(ctx context.Context, step *model.Step, actionDir string, actionPath string, readFile actionYamlReader, writeFile fileWriter) (*model.Action, error) { + logger := common.Logger(ctx) reader, closer, err := readFile("action.yml") if os.IsNotExist(err) { reader, closer, err = readFile("action.yaml") @@ -52,7 +52,7 @@ func readActionImpl(step *model.Step, actionDir string, actionPath string, readF Image: "Dockerfile", }, } - log.Debugf("Using synthetic action %v for Dockerfile", action) + logger.Debugf("Using synthetic action %v for Dockerfile", action) return action, nil } if step.With != nil { @@ -84,7 +84,7 @@ func readActionImpl(step *model.Step, actionDir string, actionPath string, readF Main: "trampoline.js", }, } - log.Debugf("Using synthetic action %v", action) + logger.Debugf("Using synthetic action %v", action) return action, nil } } @@ -96,24 +96,25 @@ func readActionImpl(step *model.Step, actionDir string, actionPath string, readF defer closer.Close() action, err := model.ReadAction(reader) - log.Debugf("Read action %v from '%s'", action, "Unknown") + logger.Debugf("Read action %v from '%s'", action, "Unknown") return action, err } func maybeCopyToActionDir(ctx context.Context, step actionStep, actionDir string, actionPath string, containerActionDir string) error { + logger := common.Logger(ctx) rc := step.getRunContext() stepModel := step.getStepModel() if stepModel.Type() != model.StepTypeUsesActionRemote { return nil } - if err := removeGitIgnore(actionDir); err != nil { + if err := removeGitIgnore(ctx, actionDir); err != nil { return err } var containerActionDirCopy string containerActionDirCopy = strings.TrimSuffix(containerActionDir, actionPath) - log.Debug(containerActionDirCopy) + logger.Debug(containerActionDirCopy) if !strings.HasSuffix(containerActionDirCopy, `/`) { containerActionDirCopy += `/` @@ -126,13 +127,14 @@ func runActionImpl(step actionStep, actionDir string, remoteAction *remoteAction stepModel := step.getStepModel() return func(ctx context.Context) error { + logger := common.Logger(ctx) actionPath := "" if remoteAction != nil && remoteAction.Path != "" { actionPath = remoteAction.Path } action := step.getActionModel() - log.Debugf("About to run action %v", action) + logger.Debugf("About to run action %v", action) if remoteAction != nil { rc.ActionRepository = fmt.Sprintf("%s/%s", remoteAction.Org, remoteAction.Repo) @@ -150,15 +152,15 @@ func runActionImpl(step actionStep, actionDir string, remoteAction *remoteAction // we need to merge with github-env again, since at the step setup // time, we don't have all environment prepared - mergeIntoMap(step.getEnv(), rc.withGithubEnv(map[string]string{})) + mergeIntoMap(step.getEnv(), rc.withGithubEnv(ctx, map[string]string{})) populateEnvsFromSavedState(step.getEnv(), step, rc) - populateEnvsFromInput(step.getEnv(), action, rc) + populateEnvsFromInput(ctx, step.getEnv(), action, rc) actionLocation := path.Join(actionDir, actionPath) actionName, containerActionDir := getContainerActionPaths(stepModel, actionLocation, rc) - log.Debugf("type=%v actionDir=%s actionPath=%s workdir=%s actionCacheDir=%s actionName=%s containerActionDir=%s", stepModel.Type(), actionDir, actionPath, rc.Config.Workdir, rc.ActionCacheDir(), actionName, containerActionDir) + logger.Debugf("type=%v actionDir=%s actionPath=%s workdir=%s actionCacheDir=%s actionName=%s containerActionDir=%s", stepModel.Type(), actionDir, actionPath, rc.Config.Workdir, rc.ActionCacheDir(), actionName, containerActionDir) switch action.Runs.Using { case model.ActionRunsUsingNode12, model.ActionRunsUsingNode16: @@ -166,7 +168,7 @@ func runActionImpl(step actionStep, actionDir string, remoteAction *remoteAction return err } containerArgs := []string{"node", path.Join(containerActionDir, action.Runs.Main)} - log.Debugf("executing remote job container: %s", containerArgs) + logger.Debugf("executing remote job container: %s", containerArgs) return rc.execJobContainer(containerArgs, *step.getEnv(), "", "")(ctx) case model.ActionRunsUsingDocker: location := actionLocation @@ -195,11 +197,11 @@ func runActionImpl(step actionStep, actionDir string, remoteAction *remoteAction // files in .gitignore are not copied in a Docker container // this causes issues with actions that ignore other important resources // such as `node_modules` for example -func removeGitIgnore(directory string) error { +func removeGitIgnore(ctx context.Context, directory string) error { gitIgnorePath := path.Join(directory, ".gitignore") if _, err := os.Stat(gitIgnorePath); err == nil { // .gitignore exists - log.Debugf("Removing %s before docker cp", gitIgnorePath) + common.Logger(ctx).Debugf("Removing %s before docker cp", gitIgnorePath) err := os.Remove(gitIgnorePath) if err != nil { return err @@ -211,6 +213,7 @@ func removeGitIgnore(directory string) error { // TODO: break out parts of function to reduce complexicity // nolint:gocyclo func execAsDocker(ctx context.Context, step actionStep, actionName string, basedir string, localAction bool) error { + logger := common.Logger(ctx) rc := step.getRunContext() action := step.getActionModel() @@ -246,7 +249,7 @@ func execAsDocker(ctx context.Context, step actionStep, actionName string, based } if !correctArchExists || rc.Config.ForceRebuild { - log.Debugf("image '%s' for architecture '%s' will be built from context '%s", image, rc.Config.ContainerArchitecture, contextDir) + logger.Debugf("image '%s' for architecture '%s' will be built from context '%s", image, rc.Config.ContainerArchitecture, contextDir) var actionContainer container.Container if localAction { actionContainer = rc.JobContainer @@ -258,19 +261,19 @@ func execAsDocker(ctx context.Context, step actionStep, actionName string, based Platform: rc.Config.ContainerArchitecture, }) } else { - log.Debugf("image '%s' for architecture '%s' already exists", image, rc.Config.ContainerArchitecture) + logger.Debugf("image '%s' for architecture '%s' already exists", image, rc.Config.ContainerArchitecture) } } - eval := rc.NewStepExpressionEvaluator(step) - cmd, err := shellquote.Split(eval.Interpolate(step.getStepModel().With["args"])) + eval := rc.NewStepExpressionEvaluator(ctx, step) + cmd, err := shellquote.Split(eval.Interpolate(ctx, step.getStepModel().With["args"])) if err != nil { return err } if len(cmd) == 0 { cmd = action.Runs.Args - evalDockerArgs(step, action, &cmd) + evalDockerArgs(ctx, step, action, &cmd) } - entrypoint := strings.Fields(eval.Interpolate(step.getStepModel().With["entrypoint"])) + entrypoint := strings.Fields(eval.Interpolate(ctx, step.getStepModel().With["entrypoint"])) if len(entrypoint) == 0 { if action.Runs.Entrypoint != "" { entrypoint, err = shellquote.Split(action.Runs.Entrypoint) @@ -293,7 +296,7 @@ func execAsDocker(ctx context.Context, step actionStep, actionName string, based ).Finally(stepContainer.Close())(ctx) } -func evalDockerArgs(step step, action *model.Action, cmd *[]string) { +func evalDockerArgs(ctx context.Context, step step, action *model.Action, cmd *[]string) { rc := step.getRunContext() stepModel := step.getStepModel() oldInputs := rc.Inputs @@ -301,26 +304,26 @@ func evalDockerArgs(step step, action *model.Action, cmd *[]string) { rc.Inputs = oldInputs }() inputs := make(map[string]interface{}) - eval := rc.NewExpressionEvaluator() + eval := rc.NewExpressionEvaluator(ctx) // Set Defaults for k, input := range action.Inputs { - inputs[k] = eval.Interpolate(input.Default) + inputs[k] = eval.Interpolate(ctx, input.Default) } if stepModel.With != nil { for k, v := range stepModel.With { - inputs[k] = eval.Interpolate(v) + inputs[k] = eval.Interpolate(ctx, v) } } rc.Inputs = inputs - stepEE := rc.NewStepExpressionEvaluator(step) + stepEE := rc.NewStepExpressionEvaluator(ctx, step) for i, v := range *cmd { - (*cmd)[i] = stepEE.Interpolate(v) + (*cmd)[i] = stepEE.Interpolate(ctx, v) } mergeIntoMap(step.getEnv(), action.Runs.Env) - ee := rc.NewStepExpressionEvaluator(step) + ee := rc.NewStepExpressionEvaluator(ctx, step) for k, v := range *step.getEnv() { - (*step.getEnv())[k] = ee.Interpolate(v) + (*step.getEnv())[k] = ee.Interpolate(ctx, v) } } @@ -368,7 +371,7 @@ func newStepContainer(ctx context.Context, step step, image string, cmd []string return stepContainer } -func (rc *RunContext) setupActionInputs(step actionStep) { +func (rc *RunContext) setupActionInputs(ctx context.Context, step actionStep) { if step.getActionModel() == nil { // e.g. local checkout skip has no action model return @@ -377,14 +380,14 @@ func (rc *RunContext) setupActionInputs(step actionStep) { stepModel := step.getStepModel() action := step.getActionModel() - eval := rc.NewExpressionEvaluator() + eval := rc.NewExpressionEvaluator(ctx) inputs := make(map[string]interface{}) for k, input := range action.Inputs { - inputs[k] = eval.Interpolate(input.Default) + inputs[k] = eval.Interpolate(ctx, input.Default) } if stepModel.With != nil { for k, v := range stepModel.With { - inputs[k] = eval.Interpolate(v) + inputs[k] = eval.Interpolate(ctx, v) } } @@ -401,13 +404,13 @@ func populateEnvsFromSavedState(env *map[string]string, step actionStep, rc *Run } } -func populateEnvsFromInput(env *map[string]string, action *model.Action, rc *RunContext) { - eval := rc.NewExpressionEvaluator() +func populateEnvsFromInput(ctx context.Context, env *map[string]string, action *model.Action, rc *RunContext) { + eval := rc.NewExpressionEvaluator(ctx) for inputID, input := range action.Inputs { envKey := regexp.MustCompile("[^A-Z0-9-]").ReplaceAllString(strings.ToUpper(inputID), "_") envKey = fmt.Sprintf("INPUT_%s", envKey) if _, ok := (*env)[envKey]; !ok { - (*env)[envKey] = eval.Interpolate(input.Default) + (*env)[envKey] = eval.Interpolate(ctx, input.Default) } } } @@ -468,7 +471,8 @@ func hasPreStep(step actionStep) common.Conditional { func runPreStep(step actionStep) common.Executor { return func(ctx context.Context) error { - common.Logger(ctx).Debugf("run pre step for '%s'", step.getStepModel()) + logger := common.Logger(ctx) + logger.Debugf("run pre step for '%s'", step.getStepModel()) rc := step.getRunContext() stepModel := step.getStepModel() @@ -501,12 +505,12 @@ func runPreStep(step actionStep) common.Executor { } containerArgs := []string{"node", path.Join(containerActionDir, action.Runs.Pre)} - log.Debugf("executing remote job container: %s", containerArgs) + logger.Debugf("executing remote job container: %s", containerArgs) return rc.execJobContainer(containerArgs, *step.getEnv(), "", "")(ctx) case model.ActionRunsUsingComposite: - step.getCompositeRunContext().updateCompositeRunContext(step.getRunContext(), step) + step.getCompositeRunContext(ctx).updateCompositeRunContext(ctx, step.getRunContext(), step) return step.getCompositeSteps().pre(ctx) default: @@ -522,17 +526,17 @@ func shouldRunPostStep(step actionStep) common.Conditional { stepResult := stepResults[step.getStepModel().ID] if stepResult == nil { - log.Debugf("skip post step for '%s'; step was not executed", step.getStepModel()) + log.WithField("stepResult", model.StepStatusSkipped).Debugf("skipping post step for '%s'; step was not executed", step.getStepModel()) return false } if stepResult.Conclusion == model.StepStatusSkipped { - log.Debugf("skip post step for '%s'; main step was skipped", step.getStepModel()) + log.WithField("stepResult", model.StepStatusSkipped).Debugf("skipping post step for '%s'; main step was skipped", step.getStepModel()) return false } if step.getActionModel() == nil { - log.Debugf("skip post step for '%s': no action model available", step.getStepModel()) + log.WithField("stepResult", model.StepStatusSkipped).Debugf("skipping post step for '%s': no action model available", step.getStepModel()) return false } @@ -552,7 +556,8 @@ func hasPostStep(step actionStep) common.Conditional { func runPostStep(step actionStep) common.Executor { return func(ctx context.Context) error { - common.Logger(ctx).Debugf("run post step for '%s'", step.getStepModel()) + logger := common.Logger(ctx) + logger.Debugf("run post step for '%s'", step.getStepModel()) rc := step.getRunContext() stepModel := step.getStepModel() @@ -584,7 +589,7 @@ func runPostStep(step actionStep) common.Executor { populateEnvsFromSavedState(step.getEnv(), step, rc) containerArgs := []string{"node", path.Join(containerActionDir, action.Runs.Post)} - log.Debugf("executing remote job container: %s", containerArgs) + logger.Debugf("executing remote job container: %s", containerArgs) return rc.execJobContainer(containerArgs, *step.getEnv(), "", "")(ctx) @@ -593,7 +598,7 @@ func runPostStep(step actionStep) common.Executor { return err } - step.getCompositeRunContext().updateCompositeRunContext(step.getRunContext(), step) + step.getCompositeRunContext(ctx).updateCompositeRunContext(ctx, step.getRunContext(), step) return step.getCompositeSteps().post(ctx) default: diff --git a/pkg/runner/action_composite.go b/pkg/runner/action_composite.go index 924bc7b..a033bdb 100644 --- a/pkg/runner/action_composite.go +++ b/pkg/runner/action_composite.go @@ -8,32 +8,32 @@ import ( "github.com/nektos/act/pkg/model" ) -func evaluteCompositeInputAndEnv(parent *RunContext, step actionStep) (inputs map[string]interface{}, env map[string]string) { - eval := parent.NewExpressionEvaluator() +func evaluteCompositeInputAndEnv(ctx context.Context, parent *RunContext, step actionStep) (inputs map[string]interface{}, env map[string]string) { + eval := parent.NewExpressionEvaluator(ctx) inputs = make(map[string]interface{}) for k, input := range step.getActionModel().Inputs { - inputs[k] = eval.Interpolate(input.Default) + inputs[k] = eval.Interpolate(ctx, input.Default) } if step.getStepModel().With != nil { for k, v := range step.getStepModel().With { - inputs[k] = eval.Interpolate(v) + inputs[k] = eval.Interpolate(ctx, v) } } env = make(map[string]string) for k, v := range parent.Env { - env[k] = eval.Interpolate(v) + env[k] = eval.Interpolate(ctx, v) } for k, v := range step.getStepModel().Environment() { - env[k] = eval.Interpolate(v) + env[k] = eval.Interpolate(ctx, v) } return inputs, env } -func newCompositeRunContext(parent *RunContext, step actionStep, actionPath string) *RunContext { - inputs, env := evaluteCompositeInputAndEnv(parent, step) +func newCompositeRunContext(ctx context.Context, parent *RunContext, step actionStep, actionPath string) *RunContext { + inputs, env := evaluteCompositeInputAndEnv(ctx, parent, step) // run with the global config but without secrets configCopy := *(parent.Config) @@ -70,8 +70,8 @@ func newCompositeRunContext(parent *RunContext, step actionStep, actionPath stri // This updates a composite context inputs, env and masks. // This is needed to re-evalute/update that context between pre/main/post steps. // Some of the inputs/env may requires the results of in-between steps. -func (rc *RunContext) updateCompositeRunContext(parent *RunContext, step actionStep) { - inputs, env := evaluteCompositeInputAndEnv(parent, step) +func (rc *RunContext) updateCompositeRunContext(ctx context.Context, parent *RunContext, step actionStep) { + inputs, env := evaluteCompositeInputAndEnv(ctx, parent, step) rc.Inputs = inputs rc.Env = env @@ -83,21 +83,21 @@ func execAsComposite(step actionStep) common.Executor { action := step.getActionModel() return func(ctx context.Context) error { - compositerc := step.getCompositeRunContext() + compositerc := step.getCompositeRunContext(ctx) steps := step.getCompositeSteps() ctx = WithCompositeLogger(ctx, &compositerc.Masks) - compositerc.updateCompositeRunContext(rc, step) + compositerc.updateCompositeRunContext(ctx, rc, step) err := steps.main(ctx) // Map outputs from composite RunContext to job RunContext - eval := compositerc.NewExpressionEvaluator() + eval := compositerc.NewExpressionEvaluator(ctx) for outputName, output := range action.Outputs { rc.setOutput(ctx, map[string]string{ "name": outputName, - }, eval.Interpolate(output.Value)) + }, eval.Interpolate(ctx, output.Value)) } rc.Masks = append(rc.Masks, compositerc.Masks...) @@ -140,12 +140,13 @@ func (rc *RunContext) compositeExecutor(action *model.Action) *compositeSteps { preSteps = append(preSteps, step.pre()) steps = append(steps, func(ctx context.Context) error { + logger := common.Logger(ctx) err := step.main()(ctx) if err != nil { - common.Logger(ctx).Errorf("%v", err) + logger.Errorf("%v", err) common.SetJobError(ctx, err) } else if ctx.Err() != nil { - common.Logger(ctx).Errorf("%v", ctx.Err()) + logger.Errorf("%v", ctx.Err()) common.SetJobError(ctx, ctx.Err()) } return nil diff --git a/pkg/runner/action_test.go b/pkg/runner/action_test.go index 14a5102..733daa9 100644 --- a/pkg/runner/action_test.go +++ b/pkg/runner/action_test.go @@ -130,7 +130,7 @@ runs: closerMock.On("Close") } - action, err := readActionImpl(tt.step, "actionDir", "actionPath", readFile, writeFile) + action, err := readActionImpl(context.Background(), tt.step, "actionDir", "actionPath", readFile, writeFile) assert.Nil(t, err) assert.Equal(t, tt.expected, action) diff --git a/pkg/runner/command.go b/pkg/runner/command.go index ce77bdf..a68be16 100755 --- a/pkg/runner/command.go +++ b/pkg/runner/command.go @@ -82,6 +82,7 @@ func (rc *RunContext) setEnv(ctx context.Context, kvPairs map[string]string, arg rc.Env[kvPairs["name"]] = arg } func (rc *RunContext) setOutput(ctx context.Context, kvPairs map[string]string, arg string) { + logger := common.Logger(ctx) stepID := rc.CurrentStep outputName := kvPairs["name"] if outputMapping, ok := rc.OutputMappings[MappableOutput{StepID: stepID, OutputName: outputName}]; ok { @@ -91,11 +92,11 @@ func (rc *RunContext) setOutput(ctx context.Context, kvPairs map[string]string, result, ok := rc.StepResults[stepID] if !ok { - common.Logger(ctx).Infof(" \U00002757 no outputs used step '%s'", stepID) + logger.Infof(" \U00002757 no outputs used step '%s'", stepID) return } - common.Logger(ctx).Infof(" \U00002699 ::set-output:: %s=%s", outputName, arg) + logger.Infof(" \U00002699 ::set-output:: %s=%s", outputName, arg) result.Outputs[outputName] = arg } func (rc *RunContext) addPath(ctx context.Context, arg string) { diff --git a/pkg/runner/command_test.go b/pkg/runner/command_test.go index 1c72768..0f3d32b 100644 --- a/pkg/runner/command_test.go +++ b/pkg/runner/command_test.go @@ -164,7 +164,7 @@ func TestAddmaskUsemask(t *testing.T) { re := captureOutput(t, func() { ctx := context.Background() - ctx = WithJobLogger(ctx, "testjob", config, &rc.Masks) + ctx = WithJobLogger(ctx, "0", "testjob", config, &rc.Masks) handler := rc.commandHandler(ctx) handler("::add-mask::secret\n") diff --git a/pkg/runner/expression.go b/pkg/runner/expression.go index ad03c21..ab54e5e 100644 --- a/pkg/runner/expression.go +++ b/pkg/runner/expression.go @@ -1,24 +1,25 @@ package runner import ( + "context" "fmt" "regexp" "strings" + "github.com/nektos/act/pkg/common" "github.com/nektos/act/pkg/exprparser" - log "github.com/sirupsen/logrus" "gopkg.in/yaml.v3" ) // ExpressionEvaluator is the interface for evaluating expressions type ExpressionEvaluator interface { - evaluate(string, exprparser.DefaultStatusCheck) (interface{}, error) - EvaluateYamlNode(node *yaml.Node) error - Interpolate(string) string + evaluate(context.Context, string, exprparser.DefaultStatusCheck) (interface{}, error) + EvaluateYamlNode(context.Context, *yaml.Node) error + Interpolate(context.Context, string) string } // NewExpressionEvaluator creates a new evaluator -func (rc *RunContext) NewExpressionEvaluator() ExpressionEvaluator { +func (rc *RunContext) NewExpressionEvaluator(ctx context.Context) ExpressionEvaluator { // todo: cleanup EvaluationEnvironment creation job := rc.Run.Job() strategy := make(map[string]interface{}) @@ -38,7 +39,7 @@ func (rc *RunContext) NewExpressionEvaluator() ExpressionEvaluator { } ee := &exprparser.EvaluationEnvironment{ - Github: rc.getGithubContext(), + Github: rc.getGithubContext(ctx), Env: rc.GetEnv(), Job: rc.getJobContext(), // todo: should be unavailable @@ -65,7 +66,7 @@ func (rc *RunContext) NewExpressionEvaluator() ExpressionEvaluator { } // NewExpressionEvaluator creates a new evaluator -func (rc *RunContext) NewStepExpressionEvaluator(step step) ExpressionEvaluator { +func (rc *RunContext) NewStepExpressionEvaluator(ctx context.Context, step step) ExpressionEvaluator { // todo: cleanup EvaluationEnvironment creation job := rc.Run.Job() strategy := make(map[string]interface{}) @@ -85,7 +86,7 @@ func (rc *RunContext) NewStepExpressionEvaluator(step step) ExpressionEvaluator } ee := &exprparser.EvaluationEnvironment{ - Github: rc.getGithubContext(), + Github: rc.getGithubContext(ctx), Env: *step.getEnv(), Job: rc.getJobContext(), Steps: rc.getStepsContext(), @@ -115,14 +116,18 @@ type expressionEvaluator struct { interpreter exprparser.Interpreter } -func (ee expressionEvaluator) evaluate(in string, defaultStatusCheck exprparser.DefaultStatusCheck) (interface{}, error) { - log.Debugf("evaluating expression '%s'", in) +func (ee expressionEvaluator) evaluate(ctx context.Context, in string, defaultStatusCheck exprparser.DefaultStatusCheck) (interface{}, error) { + logger := common.Logger(ctx) + logger.Debugf("evaluating expression '%s'", in) evaluated, err := ee.interpreter.Evaluate(in, defaultStatusCheck) - log.Debugf("expression '%s' evaluated to '%t'", in, evaluated) + + printable := regexp.MustCompile(`::add-mask::.*`).ReplaceAllString(fmt.Sprintf("%t", evaluated), "::add-mask::***)") + logger.Debugf("expression '%s' evaluated to '%s'", in, printable) + return evaluated, err } -func (ee expressionEvaluator) evaluateScalarYamlNode(node *yaml.Node) error { +func (ee expressionEvaluator) evaluateScalarYamlNode(ctx context.Context, node *yaml.Node) error { var in string if err := node.Decode(&in); err != nil { return err @@ -130,21 +135,21 @@ func (ee expressionEvaluator) evaluateScalarYamlNode(node *yaml.Node) error { if !strings.Contains(in, "${{") || !strings.Contains(in, "}}") { return nil } - expr, _ := rewriteSubExpression(in, false) - res, err := ee.evaluate(expr, exprparser.DefaultStatusCheckNone) + expr, _ := rewriteSubExpression(ctx, in, false) + res, err := ee.evaluate(ctx, expr, exprparser.DefaultStatusCheckNone) if err != nil { return err } return node.Encode(res) } -func (ee expressionEvaluator) evaluateMappingYamlNode(node *yaml.Node) error { +func (ee expressionEvaluator) evaluateMappingYamlNode(ctx context.Context, node *yaml.Node) error { // GitHub has this undocumented feature to merge maps, called insert directive insertDirective := regexp.MustCompile(`\${{\s*insert\s*}}`) for i := 0; i < len(node.Content)/2; { k := node.Content[i*2] v := node.Content[i*2+1] - if err := ee.EvaluateYamlNode(v); err != nil { + if err := ee.EvaluateYamlNode(ctx, v); err != nil { return err } var sk string @@ -153,7 +158,7 @@ func (ee expressionEvaluator) evaluateMappingYamlNode(node *yaml.Node) error { node.Content = append(append(node.Content[:i*2], v.Content...), node.Content[(i+1)*2:]...) i += len(v.Content) / 2 } else { - if err := ee.EvaluateYamlNode(k); err != nil { + if err := ee.EvaluateYamlNode(ctx, k); err != nil { return err } i++ @@ -162,12 +167,12 @@ func (ee expressionEvaluator) evaluateMappingYamlNode(node *yaml.Node) error { return nil } -func (ee expressionEvaluator) evaluateSequenceYamlNode(node *yaml.Node) error { +func (ee expressionEvaluator) evaluateSequenceYamlNode(ctx context.Context, node *yaml.Node) error { for i := 0; i < len(node.Content); { v := node.Content[i] // Preserve nested sequences wasseq := v.Kind == yaml.SequenceNode - if err := ee.EvaluateYamlNode(v); err != nil { + if err := ee.EvaluateYamlNode(ctx, v); err != nil { return err } // GitHub has this undocumented feature to merge sequences / arrays @@ -182,28 +187,28 @@ func (ee expressionEvaluator) evaluateSequenceYamlNode(node *yaml.Node) error { return nil } -func (ee expressionEvaluator) EvaluateYamlNode(node *yaml.Node) error { +func (ee expressionEvaluator) EvaluateYamlNode(ctx context.Context, node *yaml.Node) error { switch node.Kind { case yaml.ScalarNode: - return ee.evaluateScalarYamlNode(node) + return ee.evaluateScalarYamlNode(ctx, node) case yaml.MappingNode: - return ee.evaluateMappingYamlNode(node) + return ee.evaluateMappingYamlNode(ctx, node) case yaml.SequenceNode: - return ee.evaluateSequenceYamlNode(node) + return ee.evaluateSequenceYamlNode(ctx, node) default: return nil } } -func (ee expressionEvaluator) Interpolate(in string) string { +func (ee expressionEvaluator) Interpolate(ctx context.Context, in string) string { if !strings.Contains(in, "${{") || !strings.Contains(in, "}}") { return in } - expr, _ := rewriteSubExpression(in, true) - evaluated, err := ee.evaluate(expr, exprparser.DefaultStatusCheckNone) + expr, _ := rewriteSubExpression(ctx, in, true) + evaluated, err := ee.evaluate(ctx, expr, exprparser.DefaultStatusCheckNone) if err != nil { - log.Errorf("Unable to interpolate expression '%s': %s", expr, err) + common.Logger(ctx).Errorf("Unable to interpolate expression '%s': %s", expr, err) return "" } @@ -216,10 +221,10 @@ func (ee expressionEvaluator) Interpolate(in string) string { } // EvalBool evaluates an expression against given evaluator -func EvalBool(evaluator ExpressionEvaluator, expr string, defaultStatusCheck exprparser.DefaultStatusCheck) (bool, error) { - nextExpr, _ := rewriteSubExpression(expr, false) +func EvalBool(ctx context.Context, evaluator ExpressionEvaluator, expr string, defaultStatusCheck exprparser.DefaultStatusCheck) (bool, error) { + nextExpr, _ := rewriteSubExpression(ctx, expr, false) - evaluated, err := evaluator.evaluate(nextExpr, defaultStatusCheck) + evaluated, err := evaluator.evaluate(ctx, nextExpr, defaultStatusCheck) if err != nil { return false, err } @@ -232,7 +237,7 @@ func escapeFormatString(in string) string { } //nolint:gocyclo -func rewriteSubExpression(in string, forceFormat bool) (string, error) { +func rewriteSubExpression(ctx context.Context, in string, forceFormat bool) (string, error) { if !strings.Contains(in, "${{") || !strings.Contains(in, "}}") { return in, nil } @@ -293,7 +298,7 @@ func rewriteSubExpression(in string, forceFormat bool) (string, error) { out := fmt.Sprintf("format('%s', %s)", strings.ReplaceAll(formatOut, "'", "''"), strings.Join(results, ", ")) if in != out { - log.Debugf("expression '%s' rewritten to '%s'", in, out) + common.Logger(ctx).Debugf("expression '%s' rewritten to '%s'", in, out) } return out, nil } diff --git a/pkg/runner/expression_test.go b/pkg/runner/expression_test.go index f6a2301..b784a9a 100644 --- a/pkg/runner/expression_test.go +++ b/pkg/runner/expression_test.go @@ -1,6 +1,7 @@ package runner import ( + "context" "fmt" "os" "regexp" @@ -76,7 +77,7 @@ func createRunContext(t *testing.T) *RunContext { func TestEvaluateRunContext(t *testing.T) { rc := createRunContext(t) - ee := rc.NewExpressionEvaluator() + ee := rc.NewExpressionEvaluator(context.Background()) tables := []struct { in string @@ -136,7 +137,7 @@ func TestEvaluateRunContext(t *testing.T) { table := table t.Run(table.in, func(t *testing.T) { assertObject := assert.New(t) - out, err := ee.evaluate(table.in, exprparser.DefaultStatusCheckNone) + out, err := ee.evaluate(context.Background(), table.in, exprparser.DefaultStatusCheckNone) if table.errMesg == "" { assertObject.NoError(err, table.in) assertObject.Equal(table.out, out, table.in) @@ -154,7 +155,7 @@ func TestEvaluateStep(t *testing.T) { RunContext: rc, } - ee := rc.NewStepExpressionEvaluator(step) + ee := rc.NewStepExpressionEvaluator(context.Background(), step) tables := []struct { in string @@ -176,7 +177,7 @@ func TestEvaluateStep(t *testing.T) { table := table t.Run(table.in, func(t *testing.T) { assertObject := assert.New(t) - out, err := ee.evaluate(table.in, exprparser.DefaultStatusCheckNone) + out, err := ee.evaluate(context.Background(), table.in, exprparser.DefaultStatusCheckNone) if table.errMesg == "" { assertObject.NoError(err, table.in) assertObject.Equal(table.out, out, table.in) @@ -213,7 +214,7 @@ func TestInterpolate(t *testing.T) { }, }, } - ee := rc.NewExpressionEvaluator() + ee := rc.NewExpressionEvaluator(context.Background()) tables := []struct { in string out string @@ -255,7 +256,7 @@ func TestInterpolate(t *testing.T) { table := table t.Run("interpolate", func(t *testing.T) { assertObject := assert.New(t) - out := ee.Interpolate(table.in) + out := ee.Interpolate(context.Background(), table.in) assertObject.Equal(table.out, out, table.in) }) } @@ -332,7 +333,7 @@ func TestRewriteSubExpression(t *testing.T) { for _, table := range table { t.Run("TestRewriteSubExpression", func(t *testing.T) { assertObject := assert.New(t) - out, err := rewriteSubExpression(table.in, false) + out, err := rewriteSubExpression(context.Background(), table.in, false) if err != nil { t.Fatal(err) } @@ -356,7 +357,7 @@ func TestRewriteSubExpressionForceFormat(t *testing.T) { for _, table := range table { t.Run("TestRewriteSubExpressionForceFormat", func(t *testing.T) { assertObject := assert.New(t) - out, err := rewriteSubExpression(table.in, true) + out, err := rewriteSubExpression(context.Background(), table.in, true) if err != nil { t.Fatal(err) } diff --git a/pkg/runner/job_executor.go b/pkg/runner/job_executor.go index 766a703..8bbed6c 100644 --- a/pkg/runner/job_executor.go +++ b/pkg/runner/job_executor.go @@ -25,8 +25,9 @@ func newJobExecutor(info jobInfo, sf stepFactory, rc *RunContext) common.Executo var postExecutor common.Executor steps = append(steps, func(ctx context.Context) error { + logger := common.Logger(ctx) if len(info.matrix()) > 0 { - common.Logger(ctx).Infof("\U0001F9EA Matrix: %v", info.matrix()) + logger.Infof("\U0001F9EA Matrix: %v", info.matrix()) } return nil }) @@ -40,6 +41,7 @@ func newJobExecutor(info jobInfo, sf stepFactory, rc *RunContext) common.Executo preSteps = append(preSteps, info.startContainer()) for i, stepModel := range infoSteps { + stepModel := stepModel if stepModel == nil { return func(ctx context.Context) error { return fmt.Errorf("invalid Step %v: missing run or uses key", i) @@ -55,42 +57,44 @@ func newJobExecutor(info jobInfo, sf stepFactory, rc *RunContext) common.Executo return common.NewErrorExecutor(err) } - preSteps = append(preSteps, step.pre()) + preSteps = append(preSteps, useStepLogger(rc, stepModel, stepStagePre, step.pre())) stepExec := step.main() - steps = append(steps, func(ctx context.Context) error { - stepName := stepModel.String() - return (func(ctx context.Context) error { - err := stepExec(ctx) - if err != nil { - common.Logger(ctx).Errorf("%v", err) - common.SetJobError(ctx, err) - } else if ctx.Err() != nil { - common.Logger(ctx).Errorf("%v", ctx.Err()) - common.SetJobError(ctx, ctx.Err()) - } - return nil - })(withStepLogger(ctx, stepName)) - }) + steps = append(steps, useStepLogger(rc, stepModel, stepStageMain, func(ctx context.Context) error { + logger := common.Logger(ctx) + err := stepExec(ctx) + if err != nil { + logger.Errorf("%v", err) + common.SetJobError(ctx, err) + } else if ctx.Err() != nil { + logger.Errorf("%v", ctx.Err()) + common.SetJobError(ctx, ctx.Err()) + } + return nil + })) - // run the post exector in reverse order + postExec := useStepLogger(rc, stepModel, stepStagePost, step.post()) if postExecutor != nil { - postExecutor = step.post().Finally(postExecutor) + // run the post exector in reverse order + postExecutor = postExec.Finally(postExecutor) } else { - postExecutor = step.post() + postExecutor = postExec } } postExecutor = postExecutor.Finally(func(ctx context.Context) error { + logger := common.Logger(ctx) jobError := common.JobError(ctx) if jobError != nil { info.result("failure") + logger.WithField("jobResult", "failure").Infof("\U0001F3C1 Job failed") } else { err := info.stopContainer()(ctx) if err != nil { return err } info.result("success") + logger.WithField("jobResult", "success").Infof("\U0001F3C1 Job succeeded") } return nil @@ -114,3 +118,24 @@ func newJobExecutor(info jobInfo, sf stepFactory, rc *RunContext) common.Executo Finally(info.interpolateOutputs()). Finally(info.closeContainer()) } + +func useStepLogger(rc *RunContext, stepModel *model.Step, stage stepStage, executor common.Executor) common.Executor { + return func(ctx context.Context) error { + ctx = withStepLogger(ctx, stepModel.ID, stepModel.String(), stage.String()) + + rawLogger := common.Logger(ctx).WithField("raw_output", true) + logWriter := common.NewLineWriter(rc.commandHandler(ctx), func(s string) bool { + if rc.Config.LogOutput { + rawLogger.Infof("%s", s) + } else { + rawLogger.Debugf("%s", s) + } + return true + }) + + oldout, olderr := rc.JobContainer.ReplaceLogWriter(logWriter, logWriter) + defer rc.JobContainer.ReplaceLogWriter(oldout, olderr) + + return executor(ctx) + } +} diff --git a/pkg/runner/job_executor_test.go b/pkg/runner/job_executor_test.go index 4d892fe..8299f63 100644 --- a/pkg/runner/job_executor_test.go +++ b/pkg/runner/job_executor_test.go @@ -3,9 +3,11 @@ package runner import ( "context" "fmt" + "io" "testing" "github.com/nektos/act/pkg/common" + "github.com/nektos/act/pkg/container" "github.com/nektos/act/pkg/model" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/mock" @@ -75,6 +77,14 @@ func (jim *jobInfoMock) result(result string) { jim.Called(result) } +type jobContainerMock struct { + container.Container +} + +func (jcm *jobContainerMock) ReplaceLogWriter(stdout, stderr io.Writer) (io.Writer, io.Writer) { + return nil, nil +} + type stepFactoryMock struct { mock.Mock } @@ -236,7 +246,9 @@ func TestNewJobExecutor(t *testing.T) { ctx := common.WithJobErrorContainer(context.Background()) jim := &jobInfoMock{} sfm := &stepFactoryMock{} - rc := &RunContext{} + rc := &RunContext{ + JobContainer: &jobContainerMock{}, + } executorOrder := make([]string, 0) jim.On("steps").Return(tt.steps) diff --git a/pkg/runner/logger.go b/pkg/runner/logger.go index f4217a1..77c34ea 100644 --- a/pkg/runner/logger.go +++ b/pkg/runner/logger.go @@ -58,7 +58,7 @@ func WithMasks(ctx context.Context, masks *[]string) context.Context { } // WithJobLogger attaches a new logger to context that is aware of steps -func WithJobLogger(ctx context.Context, jobName string, config *Config, masks *[]string) context.Context { +func WithJobLogger(ctx context.Context, jobID string, jobName string, config *Config, masks *[]string) context.Context { mux.Lock() defer mux.Unlock() @@ -82,7 +82,11 @@ func WithJobLogger(ctx context.Context, jobName string, config *Config, masks *[ logger.SetFormatter(formatter) logger.SetOutput(os.Stdout) logger.SetLevel(logrus.GetLevel()) - rtn := logger.WithFields(logrus.Fields{"job": jobName, "dryrun": common.Dryrun(ctx)}).WithContext(ctx) + rtn := logger.WithFields(logrus.Fields{ + "job": jobName, + "jobID": jobID, + "dryrun": common.Dryrun(ctx), + }).WithContext(ctx) return common.WithLogger(ctx, rtn) } @@ -92,8 +96,12 @@ func WithCompositeLogger(ctx context.Context, masks *[]string) context.Context { return common.WithLogger(ctx, common.Logger(ctx).WithFields(logrus.Fields{}).WithContext(ctx)) } -func withStepLogger(ctx context.Context, stepName string) context.Context { - rtn := common.Logger(ctx).WithFields(logrus.Fields{"step": stepName}) +func withStepLogger(ctx context.Context, stepID string, stepName string, stageName string) context.Context { + rtn := common.Logger(ctx).WithFields(logrus.Fields{ + "step": stepName, + "stepID": stepID, + "stage": stageName, + }) return common.WithLogger(ctx, rtn) } @@ -146,26 +154,34 @@ func (f *jobLogFormatter) Format(entry *logrus.Entry) ([]byte, error) { func (f *jobLogFormatter) printColored(b *bytes.Buffer, entry *logrus.Entry) { entry.Message = strings.TrimSuffix(entry.Message, "\n") jobName := entry.Data["job"] + debugFlag := "" + if entry.Level == logrus.DebugLevel { + debugFlag = "[DEBUG] " + } if entry.Data["raw_output"] == true { fmt.Fprintf(b, "\x1b[%dm|\x1b[0m %s", f.color, entry.Message) } else if entry.Data["dryrun"] == true { - fmt.Fprintf(b, "\x1b[1m\x1b[%dm\x1b[7m*DRYRUN*\x1b[0m \x1b[%dm[%s] \x1b[0m%s", gray, f.color, jobName, entry.Message) + fmt.Fprintf(b, "\x1b[1m\x1b[%dm\x1b[7m*DRYRUN*\x1b[0m \x1b[%dm[%s] \x1b[0m%s%s", gray, f.color, jobName, debugFlag, entry.Message) } else { - fmt.Fprintf(b, "\x1b[%dm[%s] \x1b[0m%s", f.color, jobName, entry.Message) + fmt.Fprintf(b, "\x1b[%dm[%s] \x1b[0m%s%s", f.color, jobName, debugFlag, entry.Message) } } func (f *jobLogFormatter) print(b *bytes.Buffer, entry *logrus.Entry) { entry.Message = strings.TrimSuffix(entry.Message, "\n") jobName := entry.Data["job"] + debugFlag := "" + if entry.Level == logrus.DebugLevel { + debugFlag = "[DEBUG] " + } if entry.Data["raw_output"] == true { fmt.Fprintf(b, "[%s] | %s", jobName, entry.Message) } else if entry.Data["dryrun"] == true { - fmt.Fprintf(b, "*DRYRUN* [%s] %s", jobName, entry.Message) + fmt.Fprintf(b, "*DRYRUN* [%s] %s%s", jobName, debugFlag, entry.Message) } else { - fmt.Fprintf(b, "[%s] %s", jobName, entry.Message) + fmt.Fprintf(b, "[%s] %s%s", jobName, debugFlag, entry.Message) } } diff --git a/pkg/runner/run_context.go b/pkg/runner/run_context.go index 66cfa7b..c50005f 100644 --- a/pkg/runner/run_context.go +++ b/pkg/runner/run_context.go @@ -123,11 +123,11 @@ func (rc *RunContext) GetBindsAndMounts() ([]string, map[string]string) { } func (rc *RunContext) startJobContainer() common.Executor { - image := rc.platformImage() - hostname := rc.hostname() - return func(ctx context.Context) error { - rawLogger := common.Logger(ctx).WithField("raw_output", true) + logger := common.Logger(ctx) + image := rc.platformImage(ctx) + hostname := rc.hostname(ctx) + rawLogger := logger.WithField("raw_output", true) logWriter := common.NewLineWriter(rc.commandHandler(ctx), func(s string) bool { if rc.Config.LogOutput { rawLogger.Infof("%s", s) @@ -137,12 +137,12 @@ func (rc *RunContext) startJobContainer() common.Executor { return true }) - username, password, err := rc.handleCredentials() + username, password, err := rc.handleCredentials(ctx) if err != nil { return fmt.Errorf("failed to handle credentials: %s", err) } - common.Logger(ctx).Infof("\U0001f680 Start image=%s", image) + logger.Infof("\U0001f680 Start image=%s", image) name := rc.jobContainerName() envList := make([]string, 0) @@ -176,7 +176,7 @@ func (rc *RunContext) startJobContainer() common.Executor { var copyWorkspace bool var copyToPath string if !rc.Config.BindWorkdir { - copyToPath, copyWorkspace = rc.localCheckoutPath() + copyToPath, copyWorkspace = rc.localCheckoutPath(ctx) copyToPath = filepath.Join(rc.Config.ContainerWorkdir(), copyToPath) } @@ -243,9 +243,9 @@ func (rc *RunContext) ActionCacheDir() string { // Interpolate outputs after a job is done func (rc *RunContext) interpolateOutputs() common.Executor { return func(ctx context.Context) error { - ee := rc.NewExpressionEvaluator() + ee := rc.NewExpressionEvaluator(ctx) for k, v := range rc.Run.Job().Outputs { - interpolated := ee.Interpolate(v) + interpolated := ee.Interpolate(ctx, v) if v != interpolated { rc.Run.Job().Outputs[k] = interpolated } @@ -299,20 +299,20 @@ func (rc *RunContext) Executor() common.Executor { } } -func (rc *RunContext) platformImage() string { +func (rc *RunContext) platformImage(ctx context.Context) string { job := rc.Run.Job() c := job.Container() if c != nil { - return rc.ExprEval.Interpolate(c.Image) + return rc.ExprEval.Interpolate(ctx, c.Image) } if job.RunsOn() == nil { - log.Errorf("'runs-on' key not defined in %s", rc.String()) + common.Logger(ctx).Errorf("'runs-on' key not defined in %s", rc.String()) } for _, runnerLabel := range job.RunsOn() { - platformName := rc.ExprEval.Interpolate(runnerLabel) + platformName := rc.ExprEval.Interpolate(ctx, runnerLabel) image := rc.Config.Platforms[strings.ToLower(platformName)] if image != "" { return image @@ -322,7 +322,8 @@ func (rc *RunContext) platformImage() string { return "" } -func (rc *RunContext) hostname() string { +func (rc *RunContext) hostname(ctx context.Context) string { + logger := common.Logger(ctx) job := rc.Run.Job() c := job.Container() if c == nil { @@ -333,12 +334,12 @@ func (rc *RunContext) hostname() string { hostname := optionsFlags.StringP("hostname", "h", "", "") optionsArgs, err := shellquote.Split(c.Options) if err != nil { - log.Warnf("Cannot parse container options: %s", c.Options) + logger.Warnf("Cannot parse container options: %s", c.Options) return "" } err = optionsFlags.Parse(optionsArgs) if err != nil { - log.Warnf("Cannot parse container options: %s", c.Options) + logger.Warnf("Cannot parse container options: %s", c.Options) return "" } return *hostname @@ -347,23 +348,23 @@ func (rc *RunContext) hostname() string { func (rc *RunContext) isEnabled(ctx context.Context) (bool, error) { job := rc.Run.Job() l := common.Logger(ctx) - runJob, err := EvalBool(rc.ExprEval, job.If.Value, exprparser.DefaultStatusCheckSuccess) + runJob, err := EvalBool(ctx, rc.ExprEval, job.If.Value, exprparser.DefaultStatusCheckSuccess) if err != nil { return false, fmt.Errorf(" \u274C Error in if-expression: \"if: %s\" (%s)", job.If.Value, err) } if !runJob { - l.Debugf("Skipping job '%s' due to '%s'", job.Name, job.If.Value) + l.WithField("jobResult", "skipped").Debugf("Skipping job '%s' due to '%s'", job.Name, job.If.Value) return false, nil } - img := rc.platformImage() + img := rc.platformImage(ctx) if img == "" { if job.RunsOn() == nil { - log.Errorf("'runs-on' key not defined in %s", rc.String()) + l.Errorf("'runs-on' key not defined in %s", rc.String()) } for _, runnerLabel := range job.RunsOn() { - platformName := rc.ExprEval.Interpolate(runnerLabel) + platformName := rc.ExprEval.Interpolate(ctx, runnerLabel) l.Infof("\U0001F6A7 Skipping unsupported platform -- Try running with `-P %+v=...`", platformName) } return false, nil @@ -431,7 +432,8 @@ func (rc *RunContext) getStepsContext() map[string]*model.StepResult { return rc.StepResults } -func (rc *RunContext) getGithubContext() *model.GithubContext { +func (rc *RunContext) getGithubContext(ctx context.Context) *model.GithubContext { + logger := common.Logger(ctx) ghc := &model.GithubContext{ Event: make(map[string]interface{}), EventPath: ActPath + "/workflow/event.json", @@ -475,9 +477,9 @@ func (rc *RunContext) getGithubContext() *model.GithubContext { } repoPath := rc.Config.Workdir - repo, err := git.FindGithubRepo(repoPath, rc.Config.GitHubInstance, rc.Config.RemoteName) + repo, err := git.FindGithubRepo(ctx, repoPath, rc.Config.GitHubInstance, rc.Config.RemoteName) if err != nil { - log.Warningf("unable to get git repo: %v", err) + logger.Warningf("unable to get git repo: %v", err) } else { ghc.Repository = repo if ghc.RepositoryOwner == "" { @@ -488,7 +490,7 @@ func (rc *RunContext) getGithubContext() *model.GithubContext { if rc.EventJSON != "" { err = json.Unmarshal([]byte(rc.EventJSON), &ghc.Event) if err != nil { - log.Errorf("Unable to Unmarshal event '%s': %v", rc.EventJSON, err) + logger.Errorf("Unable to Unmarshal event '%s': %v", rc.EventJSON, err) } } @@ -497,7 +499,7 @@ func (rc *RunContext) getGithubContext() *model.GithubContext { ghc.HeadRef = asString(nestedMapLookup(ghc.Event, "pull_request", "head", "ref")) } - ghc.SetRefAndSha(rc.Config.DefaultBranch, repoPath) + ghc.SetRefAndSha(ctx, rc.Config.DefaultBranch, repoPath) // https://docs.github.com/en/actions/learn-github-actions/environment-variables if strings.HasPrefix(ghc.Ref, "refs/tags/") { @@ -563,8 +565,8 @@ func nestedMapLookup(m map[string]interface{}, ks ...string) (rval interface{}) } } -func (rc *RunContext) withGithubEnv(env map[string]string) map[string]string { - github := rc.getGithubContext() +func (rc *RunContext) withGithubEnv(ctx context.Context, env map[string]string) map[string]string { + github := rc.getGithubContext(ctx) env["CI"] = "true" env["GITHUB_ENV"] = ActPath + "/workflow/envs.txt" env["GITHUB_PATH"] = ActPath + "/workflow/paths.txt" @@ -609,7 +611,7 @@ func (rc *RunContext) withGithubEnv(env map[string]string) map[string]string { job := rc.Run.Job() if job.RunsOn() != nil { for _, runnerLabel := range job.RunsOn() { - platformName := rc.ExprEval.Interpolate(runnerLabel) + platformName := rc.ExprEval.Interpolate(ctx, runnerLabel) if platformName != "" { if platformName == "ubuntu-latest" { // hardcode current ubuntu-latest since we have no way to check that 'on the fly' @@ -639,12 +641,12 @@ func setActionRuntimeVars(rc *RunContext, env map[string]string) { env["ACTIONS_RUNTIME_TOKEN"] = actionsRuntimeToken } -func (rc *RunContext) localCheckoutPath() (string, bool) { +func (rc *RunContext) localCheckoutPath(ctx context.Context) (string, bool) { if rc.Config.NoSkipCheckout { return "", false } - ghContext := rc.getGithubContext() + ghContext := rc.getGithubContext(ctx) for _, step := range rc.Run.Job().Steps { if isLocalCheckout(ghContext, step) { return step.With["path"], true @@ -653,7 +655,7 @@ func (rc *RunContext) localCheckoutPath() (string, bool) { return "", false } -func (rc *RunContext) handleCredentials() (username, password string, err error) { +func (rc *RunContext) handleCredentials(ctx context.Context) (username, password string, err error) { // TODO: remove below 2 lines when we can release act with breaking changes username = rc.Config.Secrets["DOCKER_USERNAME"] password = rc.Config.Secrets["DOCKER_PASSWORD"] @@ -668,12 +670,12 @@ func (rc *RunContext) handleCredentials() (username, password string, err error) return } - ee := rc.NewExpressionEvaluator() - if username = ee.Interpolate(container.Credentials["username"]); username == "" { + ee := rc.NewExpressionEvaluator(ctx) + if username = ee.Interpolate(ctx, container.Credentials["username"]); username == "" { err = fmt.Errorf("failed to interpolate container.credentials.username") return } - if password = ee.Interpolate(container.Credentials["password"]); password == "" { + if password = ee.Interpolate(ctx, container.Credentials["password"]); password == "" { err = fmt.Errorf("failed to interpolate container.credentials.password") return } diff --git a/pkg/runner/run_context_test.go b/pkg/runner/run_context_test.go index ebd2f67..5980a8c 100644 --- a/pkg/runner/run_context_test.go +++ b/pkg/runner/run_context_test.go @@ -62,7 +62,7 @@ func TestRunContext_EvalBool(t *testing.T) { }, }, } - rc.ExprEval = rc.NewExpressionEvaluator() + rc.ExprEval = rc.NewExpressionEvaluator(context.Background()) tables := []struct { in string @@ -156,7 +156,7 @@ func TestRunContext_EvalBool(t *testing.T) { table := table t.Run(table.in, func(t *testing.T) { assertObject := assert.New(t) - b, err := EvalBool(rc.ExprEval, table.in, exprparser.DefaultStatusCheckSuccess) + b, err := EvalBool(context.Background(), rc.ExprEval, table.in, exprparser.DefaultStatusCheckSuccess) if table.wantErr { assertObject.Error(err) } @@ -365,7 +365,7 @@ func TestGetGitHubContext(t *testing.T) { OutputMappings: map[MappableOutput]MappableOutput{}, } - ghc := rc.getGithubContext() + ghc := rc.getGithubContext(context.Background()) log.Debugf("%v", ghc) @@ -413,7 +413,7 @@ func createIfTestRunContext(jobs map[string]*model.Job) *RunContext { }, }, } - rc.ExprEval = rc.NewExpressionEvaluator() + rc.ExprEval = rc.NewExpressionEvaluator(context.Background()) return rc } diff --git a/pkg/runner/runner.go b/pkg/runner/runner.go index b089097..e0bda07 100644 --- a/pkg/runner/runner.go +++ b/pkg/runner/runner.go @@ -139,8 +139,8 @@ func (runner *runnerImpl) NewPlanExecutor(plan *model.Plan) common.Executor { } if job.Strategy != nil { - strategyRc := runner.newRunContext(run, nil) - if err := strategyRc.NewExpressionEvaluator().EvaluateYamlNode(&job.Strategy.RawMatrix); err != nil { + strategyRc := runner.newRunContext(ctx, run, nil) + if err := strategyRc.NewExpressionEvaluator(ctx).EvaluateYamlNode(ctx, &job.Strategy.RawMatrix); err != nil { log.Errorf("Error while evaluating matrix: %v", err) } } @@ -155,7 +155,7 @@ func (runner *runnerImpl) NewPlanExecutor(plan *model.Plan) common.Executor { } for i, matrix := range matrixes { - rc := runner.newRunContext(run, matrix) + rc := runner.newRunContext(ctx, run, matrix) rc.JobName = rc.Name if len(matrixes) > 1 { rc.Name = fmt.Sprintf("%s-%d", rc.Name, i+1) @@ -163,7 +163,7 @@ func (runner *runnerImpl) NewPlanExecutor(plan *model.Plan) common.Executor { // evaluate environment variables since they can contain // GitHub's special environment variables. for k, v := range rc.GetEnv() { - valueEval, err := rc.ExprEval.evaluate(v, exprparser.DefaultStatusCheckNone) + valueEval, err := rc.ExprEval.evaluate(ctx, v, exprparser.DefaultStatusCheckNone) if err == nil { rc.Env[k] = fmt.Sprintf("%v", valueEval) } @@ -172,6 +172,7 @@ func (runner *runnerImpl) NewPlanExecutor(plan *model.Plan) common.Executor { maxJobNameLen = len(rc.String()) } stageExecutor = append(stageExecutor, func(ctx context.Context) error { + logger := common.Logger(ctx) jobName := fmt.Sprintf("%-*s", maxJobNameLen, rc.String()) return rc.Executor().Finally(func(ctx context.Context) error { isLastRunningContainer := func(currentStage int, currentRun int) bool { @@ -188,12 +189,12 @@ func (runner *runnerImpl) NewPlanExecutor(plan *model.Plan) common.Executor { log.Infof("Cleaning up container for job %s", rc.JobName) if err := rc.stopJobContainer()(ctx); err != nil { - log.Errorf("Error while cleaning container: %v", err) + logger.Errorf("Error while cleaning container: %v", err) } } return nil - })(common.WithJobErrorContainer(WithJobLogger(ctx, jobName, rc.Config, &rc.Masks))) + })(common.WithJobErrorContainer(WithJobLogger(ctx, rc.Run.JobID, jobName, rc.Config, &rc.Masks))) }) } pipeline = append(pipeline, common.NewParallelExecutor(maxParallel, stageExecutor...)) @@ -226,7 +227,7 @@ func handleFailure(plan *model.Plan) common.Executor { } } -func (runner *runnerImpl) newRunContext(run *model.Run, matrix map[string]interface{}) *RunContext { +func (runner *runnerImpl) newRunContext(ctx context.Context, run *model.Run, matrix map[string]interface{}) *RunContext { rc := &RunContext{ Config: runner.config, Run: run, @@ -234,7 +235,7 @@ func (runner *runnerImpl) newRunContext(run *model.Run, matrix map[string]interf StepResults: make(map[string]*model.StepResult), Matrix: matrix, } - rc.ExprEval = rc.NewExpressionEvaluator() - rc.Name = rc.ExprEval.Interpolate(run.String()) + rc.ExprEval = rc.NewExpressionEvaluator(ctx) + rc.Name = rc.ExprEval.Interpolate(ctx, run.String()) return rc } diff --git a/pkg/runner/runner_test.go b/pkg/runner/runner_test.go index d183da6..2129c43 100644 --- a/pkg/runner/runner_test.go +++ b/pkg/runner/runner_test.go @@ -261,7 +261,7 @@ func TestMaskValues(t *testing.T) { }) assertNoSecret(output, "secret value") - assertNoSecret(output, "composite secret") + assertNoSecret(output, "YWJjCg==") } func TestRunEventSecrets(t *testing.T) { diff --git a/pkg/runner/step.go b/pkg/runner/step.go index e4fb870..cf403b6 100644 --- a/pkg/runner/step.go +++ b/pkg/runner/step.go @@ -8,7 +8,6 @@ import ( "github.com/nektos/act/pkg/common" "github.com/nektos/act/pkg/exprparser" "github.com/nektos/act/pkg/model" - log "github.com/sirupsen/logrus" ) type step interface { @@ -19,7 +18,7 @@ type step interface { getRunContext() *RunContext getStepModel() *model.Step getEnv() *map[string]string - getIfExpression(stage stepStage) string + getIfExpression(context context.Context, stage stepStage) string } type stepStage int @@ -56,10 +55,11 @@ func (s stepStage) getStepName(stepModel *model.Step) string { func runStepExecutor(step step, stage stepStage, executor common.Executor) common.Executor { return func(ctx context.Context) error { + logger := common.Logger(ctx) rc := step.getRunContext() stepModel := step.getStepModel() - ifExpression := step.getIfExpression(stage) + ifExpression := step.getIfExpression(ctx, stage) rc.CurrentStep = stage.getStepName(stepModel) rc.StepResults[rc.CurrentStep] = &model.StepResult{ @@ -81,9 +81,9 @@ func runStepExecutor(step step, stage stepStage, executor common.Executor) commo } if !runStep { - log.Debugf("Skipping step '%s' due to '%s'", stepModel, ifExpression) rc.StepResults[rc.CurrentStep].Conclusion = model.StepStatusSkipped rc.StepResults[rc.CurrentStep].Outcome = model.StepStatusSkipped + logger.WithField("stepResult", rc.StepResults[rc.CurrentStep].Outcome).Debugf("Skipping step '%s' due to '%s'", stepModel, ifExpression) return nil } @@ -91,23 +91,23 @@ func runStepExecutor(step step, stage stepStage, executor common.Executor) commo if strings.Contains(stepString, "::add-mask::") { stepString = "add-mask command" } - common.Logger(ctx).Infof("\u2B50 Run %s %s", stage, stepString) + logger.Infof("\u2B50 Run %s %s", stage, stepString) err = executor(ctx) if err == nil { - common.Logger(ctx).Infof(" \u2705 Success - %s %s", stage, stepString) + logger.WithField("stepResult", rc.StepResults[rc.CurrentStep].Outcome).Infof(" \u2705 Success - %s %s", stage, stepString) } else { - common.Logger(ctx).Errorf(" \u274C Failure - %s %s", stage, stepString) - rc.StepResults[rc.CurrentStep].Outcome = model.StepStatusFailure if stepModel.ContinueOnError { - common.Logger(ctx).Infof("Failed but continue next step") + logger.Infof("Failed but continue next step") err = nil rc.StepResults[rc.CurrentStep].Conclusion = model.StepStatusSuccess } else { rc.StepResults[rc.CurrentStep].Conclusion = model.StepStatusFailure } + + logger.WithField("stepResult", rc.StepResults[rc.CurrentStep].Outcome).Errorf(" \u274C Failure - %s %s", stage, stepString) } return err } @@ -116,7 +116,7 @@ func runStepExecutor(step step, stage stepStage, executor common.Executor) commo func setupEnv(ctx context.Context, step step) error { rc := step.getRunContext() - mergeEnv(step) + mergeEnv(ctx, step) err := rc.JobContainer.UpdateFromImageEnv(step.getEnv())(ctx) if err != nil { return err @@ -131,9 +131,9 @@ func setupEnv(ctx context.Context, step step) error { } mergeIntoMap(step.getEnv(), step.getStepModel().GetEnv()) // step env should not be overwritten - exprEval := rc.NewStepExpressionEvaluator(step) + exprEval := rc.NewStepExpressionEvaluator(ctx, step) for k, v := range *step.getEnv() { - (*step.getEnv())[k] = exprEval.Interpolate(v) + (*step.getEnv())[k] = exprEval.Interpolate(ctx, v) } common.Logger(ctx).Debugf("setupEnv => %v", *step.getEnv()) @@ -141,7 +141,7 @@ func setupEnv(ctx context.Context, step step) error { return nil } -func mergeEnv(step step) { +func mergeEnv(ctx context.Context, step step) { env := step.getEnv() rc := step.getRunContext() job := rc.Run.Job() @@ -162,7 +162,7 @@ func mergeEnv(step step) { (*env)["PATH"] += `:` + p } - mergeIntoMap(env, rc.withGithubEnv(*env)) + mergeIntoMap(env, rc.withGithubEnv(ctx, *env)) } func isStepEnabled(ctx context.Context, expr string, step step, stage stepStage) (bool, error) { @@ -175,7 +175,7 @@ func isStepEnabled(ctx context.Context, expr string, step step, stage stepStage) defaultStatusCheck = exprparser.DefaultStatusCheckSuccess } - runStep, err := EvalBool(rc.NewStepExpressionEvaluator(step), expr, defaultStatusCheck) + runStep, err := EvalBool(ctx, rc.NewStepExpressionEvaluator(ctx, step), expr, defaultStatusCheck) if err != nil { return false, fmt.Errorf(" \u274C Error in if-expression: \"if: %s\" (%s)", expr, err) } diff --git a/pkg/runner/step_action_local.go b/pkg/runner/step_action_local.go index 575d78e..df73979 100644 --- a/pkg/runner/step_action_local.go +++ b/pkg/runner/step_action_local.go @@ -55,7 +55,7 @@ func (sal *stepActionLocal) main() common.Executor { } } - actionModel, err := sal.readAction(sal.Step, actionDir, "", localReader(ctx), ioutil.WriteFile) + actionModel, err := sal.readAction(ctx, sal.Step, actionDir, "", localReader(ctx), ioutil.WriteFile) if err != nil { return err } @@ -82,7 +82,7 @@ func (sal *stepActionLocal) getEnv() *map[string]string { return &sal.env } -func (sal *stepActionLocal) getIfExpression(stage stepStage) string { +func (sal *stepActionLocal) getIfExpression(context context.Context, stage stepStage) string { switch stage { case stepStageMain: return sal.Step.If.Value @@ -96,12 +96,12 @@ func (sal *stepActionLocal) getActionModel() *model.Action { return sal.action } -func (sal *stepActionLocal) getCompositeRunContext() *RunContext { +func (sal *stepActionLocal) getCompositeRunContext(ctx context.Context) *RunContext { if sal.compositeRunContext == nil { actionDir := filepath.Join(sal.RunContext.Config.Workdir, sal.Step.Uses) _, containerActionDir := getContainerActionPaths(sal.getStepModel(), actionDir, sal.RunContext) - sal.compositeRunContext = newCompositeRunContext(sal.RunContext, sal, containerActionDir) + sal.compositeRunContext = newCompositeRunContext(ctx, sal.RunContext, sal, containerActionDir) sal.compositeSteps = sal.compositeRunContext.compositeExecutor(sal.action) } return sal.compositeRunContext diff --git a/pkg/runner/step_action_local_test.go b/pkg/runner/step_action_local_test.go index 09f7597..8180d6d 100644 --- a/pkg/runner/step_action_local_test.go +++ b/pkg/runner/step_action_local_test.go @@ -21,7 +21,7 @@ func (salm *stepActionLocalMocks) runAction(step actionStep, actionDir string, r return args.Get(0).(func(context.Context) error) } -func (salm *stepActionLocalMocks) readAction(step *model.Step, actionDir string, actionPath string, readFile actionYamlReader, writeFile fileWriter) (*model.Action, error) { +func (salm *stepActionLocalMocks) readAction(ctx context.Context, step *model.Step, actionDir string, actionPath string, readFile actionYamlReader, writeFile fileWriter) (*model.Action, error) { args := salm.Called(step, actionDir, actionPath, readFile, writeFile) return args.Get(0).(*model.Action), args.Error(1) } diff --git a/pkg/runner/step_action_remote.go b/pkg/runner/step_action_remote.go index cf1ddea..9becc20 100644 --- a/pkg/runner/step_action_remote.go +++ b/pkg/runner/step_action_remote.go @@ -50,7 +50,7 @@ func (sar *stepActionRemote) prepareActionExecutor() common.Executor { sar.remoteAction.URL = sar.RunContext.Config.GitHubInstance - github := sar.RunContext.getGithubContext() + github := sar.RunContext.getGithubContext(ctx) if sar.remoteAction.IsCheckout() && isLocalCheckout(github, sar.Step) && !sar.RunContext.Config.NoSkipCheckout { common.Logger(ctx).Debugf("Skipping local actions/checkout because workdir was already copied") return nil @@ -85,14 +85,14 @@ func (sar *stepActionRemote) prepareActionExecutor() common.Executor { return common.NewPipelineExecutor( ntErr, func(ctx context.Context) error { - actionModel, err := sar.readAction(sar.Step, actionDir, sar.remoteAction.Path, remoteReader(ctx), ioutil.WriteFile) + actionModel, err := sar.readAction(ctx, sar.Step, actionDir, sar.remoteAction.Path, remoteReader(ctx), ioutil.WriteFile) sar.action = actionModel return err }, )(ctx) }, func(ctx context.Context) error { - sar.RunContext.setupActionInputs(sar) + sar.RunContext.setupActionInputs(ctx, sar) return nil }) } @@ -109,7 +109,7 @@ func (sar *stepActionRemote) main() common.Executor { return common.NewPipelineExecutor( sar.prepareActionExecutor(), runStepExecutor(sar, stepStageMain, func(ctx context.Context) error { - github := sar.RunContext.getGithubContext() + github := sar.RunContext.getGithubContext(ctx) if sar.remoteAction.IsCheckout() && isLocalCheckout(github, sar.Step) && !sar.RunContext.Config.NoSkipCheckout { common.Logger(ctx).Debugf("Skipping local actions/checkout because workdir was already copied") return nil @@ -140,10 +140,10 @@ func (sar *stepActionRemote) getEnv() *map[string]string { return &sar.env } -func (sar *stepActionRemote) getIfExpression(stage stepStage) string { +func (sar *stepActionRemote) getIfExpression(ctx context.Context, stage stepStage) string { switch stage { case stepStagePre: - github := sar.RunContext.getGithubContext() + github := sar.RunContext.getGithubContext(ctx) if sar.remoteAction.IsCheckout() && isLocalCheckout(github, sar.Step) && !sar.RunContext.Config.NoSkipCheckout { // skip local checkout pre step return "false" @@ -161,13 +161,13 @@ func (sar *stepActionRemote) getActionModel() *model.Action { return sar.action } -func (sar *stepActionRemote) getCompositeRunContext() *RunContext { +func (sar *stepActionRemote) getCompositeRunContext(ctx context.Context) *RunContext { if sar.compositeRunContext == nil { actionDir := fmt.Sprintf("%s/%s", sar.RunContext.ActionCacheDir(), strings.ReplaceAll(sar.Step.Uses, "/", "-")) actionLocation := path.Join(actionDir, sar.remoteAction.Path) _, containerActionDir := getContainerActionPaths(sar.getStepModel(), actionLocation, sar.RunContext) - sar.compositeRunContext = newCompositeRunContext(sar.RunContext, sar, containerActionDir) + sar.compositeRunContext = newCompositeRunContext(ctx, sar.RunContext, sar, containerActionDir) sar.compositeSteps = sar.compositeRunContext.compositeExecutor(sar.action) } return sar.compositeRunContext diff --git a/pkg/runner/step_action_remote_test.go b/pkg/runner/step_action_remote_test.go index 4292801..73b2331 100644 --- a/pkg/runner/step_action_remote_test.go +++ b/pkg/runner/step_action_remote_test.go @@ -19,7 +19,7 @@ type stepActionRemoteMocks struct { mock.Mock } -func (sarm *stepActionRemoteMocks) readAction(step *model.Step, actionDir string, actionPath string, readFile actionYamlReader, writeFile fileWriter) (*model.Action, error) { +func (sarm *stepActionRemoteMocks) readAction(ctx context.Context, step *model.Step, actionDir string, actionPath string, readFile actionYamlReader, writeFile fileWriter) (*model.Action, error) { args := sarm.Called(step, actionDir, actionPath, readFile, writeFile) return args.Get(0).(*model.Action), args.Error(1) } diff --git a/pkg/runner/step_docker.go b/pkg/runner/step_docker.go index e3bda18..0130b83 100644 --- a/pkg/runner/step_docker.go +++ b/pkg/runner/step_docker.go @@ -47,7 +47,7 @@ func (sd *stepDocker) getEnv() *map[string]string { return &sd.env } -func (sd *stepDocker) getIfExpression(stage stepStage) string { +func (sd *stepDocker) getIfExpression(context context.Context, stage stepStage) string { return sd.Step.If.Value } @@ -57,14 +57,14 @@ func (sd *stepDocker) runUsesContainer() common.Executor { return func(ctx context.Context) error { image := strings.TrimPrefix(step.Uses, "docker://") - eval := rc.NewExpressionEvaluator() - cmd, err := shellquote.Split(eval.Interpolate(step.With["args"])) + eval := rc.NewExpressionEvaluator(ctx) + cmd, err := shellquote.Split(eval.Interpolate(ctx, step.With["args"])) if err != nil { return err } var entrypoint []string - if entry := eval.Interpolate(step.With["entrypoint"]); entry != "" { + if entry := eval.Interpolate(ctx, step.With["entrypoint"]); entry != "" { entrypoint = []string{entry} } diff --git a/pkg/runner/step_run.go b/pkg/runner/step_run.go index 9a6fe34..87c9516 100644 --- a/pkg/runner/step_run.go +++ b/pkg/runner/step_run.go @@ -53,7 +53,7 @@ func (sr *stepRun) getEnv() *map[string]string { return &sr.env } -func (sr *stepRun) getIfExpression(stage stepStage) string { +func (sr *stepRun) getIfExpression(context context.Context, stage stepStage) string { return sr.Step.If.Value } @@ -86,12 +86,13 @@ func getScriptName(rc *RunContext, step *model.Step) string { // it will error anyway with: // OCI runtime exec failed: exec failed: container_linux.go:380: starting container process caused: exec: "${{": executable file not found in $PATH: unknown func (sr *stepRun) setupShellCommand(ctx context.Context) (name, script string, err error) { - sr.setupShell() - sr.setupWorkingDirectory() + logger := common.Logger(ctx) + sr.setupShell(ctx) + sr.setupWorkingDirectory(ctx) step := sr.Step - script = sr.RunContext.NewStepExpressionEvaluator(sr).Interpolate(step.Run) + script = sr.RunContext.NewStepExpressionEvaluator(ctx, sr).Interpolate(ctx, step.Run) scCmd := step.ShellCommand() @@ -118,9 +119,9 @@ func (sr *stepRun) setupShellCommand(ctx context.Context) (name, script string, script = fmt.Sprintf("%s\n%s\n%s", runPrepend, script, runAppend) if !strings.Contains(script, "::add-mask::") && !sr.RunContext.Config.InsecureSecrets { - common.Logger(ctx).Debugf("Wrote command \n%s\n to '%s'", script, name) + logger.Debugf("Wrote command \n%s\n to '%s'", script, name) } else { - common.Logger(ctx).Debugf("Wrote add-mask command to '%s'", name) + logger.Debugf("Wrote add-mask command to '%s'", name) } scriptPath := fmt.Sprintf("%s/%s", ActPath, name) @@ -129,7 +130,7 @@ func (sr *stepRun) setupShellCommand(ctx context.Context) (name, script string, return name, script, err } -func (sr *stepRun) setupShell() { +func (sr *stepRun) setupShell(ctx context.Context) { rc := sr.RunContext step := sr.Step @@ -137,7 +138,7 @@ func (sr *stepRun) setupShell() { step.Shell = rc.Run.Job().Defaults.Run.Shell } - step.Shell = rc.NewExpressionEvaluator().Interpolate(step.Shell) + step.Shell = rc.NewExpressionEvaluator(ctx).Interpolate(ctx, step.Shell) if step.Shell == "" { step.Shell = rc.Run.Workflow.Defaults.Run.Shell @@ -155,7 +156,7 @@ func (sr *stepRun) setupShell() { } } -func (sr *stepRun) setupWorkingDirectory() { +func (sr *stepRun) setupWorkingDirectory(ctx context.Context) { rc := sr.RunContext step := sr.Step @@ -164,7 +165,7 @@ func (sr *stepRun) setupWorkingDirectory() { } // jobs can receive context values, so we interpolate - step.WorkingDirectory = rc.NewExpressionEvaluator().Interpolate(step.WorkingDirectory) + step.WorkingDirectory = rc.NewExpressionEvaluator(ctx).Interpolate(ctx, step.WorkingDirectory) // but top level keys in workflow file like `defaults` or `env` can't if step.WorkingDirectory == "" { diff --git a/pkg/runner/step_test.go b/pkg/runner/step_test.go index 91d4538..cfce24e 100644 --- a/pkg/runner/step_test.go +++ b/pkg/runner/step_test.go @@ -230,7 +230,7 @@ func TestIsStepEnabled(t *testing.T) { // success() step := createTestStep(t, "if: success()") - assertObject.True(isStepEnabled(context.Background(), step.getIfExpression(stepStageMain), step, stepStageMain)) + assertObject.True(isStepEnabled(context.Background(), step.getIfExpression(context.Background(), stepStageMain), step, stepStageMain)) step = createTestStep(t, "if: success()") step.getRunContext().StepResults["a"] = &model.StepResult{ diff --git a/pkg/runner/testdata/mask-values/composite/action.yml b/pkg/runner/testdata/mask-values/composite/action.yml index cbeb229..08a1b79 100644 --- a/pkg/runner/testdata/mask-values/composite/action.yml +++ b/pkg/runner/testdata/mask-values/composite/action.yml @@ -6,7 +6,7 @@ runs: steps: - run: echo "secret value" shell: bash - - run: echo "::add-mask::composite secret" + - run: echo "::add-mask::$(echo "abc" | base64)" shell: bash - - run: echo "composite secret" + - run: echo "abc" | base64 shell: bash diff --git a/pkg/runner/testdata/mask-values/push.yml b/pkg/runner/testdata/mask-values/push.yml index fb7e837..befe73f 100644 --- a/pkg/runner/testdata/mask-values/push.yml +++ b/pkg/runner/testdata/mask-values/push.yml @@ -9,4 +9,4 @@ jobs: - run: echo "::add-mask::secret value" - run: echo "secret value" - uses: ./mask-values/composite - - run: echo "composite secret" + - run: echo "YWJjCg==" |