[ORCA-4531] Improve pre workflow hook error handling (#228)

* add instrumentation to pre workflow hooks

* add error handling and failure

* use interface instead of struct

* minor fix

* add error messaging to pre workflow hooks

* use underscores

* fail pr status check instead of commenting

* pass in context and use new logger

* fix test

* address feedback

* rename logging/helpers to logging/fields

use our NoopLogger instead of logur.NoopLogger

server/events/command_runner.go

@@ -14,6 +14,7 @@
 package events
 
 import (
+	"context"
 	"fmt"
 	"strconv"
 	"time"
@@ -27,6 +28,7 @@ import (
 	"github.com/runatlantis/atlantis/server/events/models"
 	"github.com/runatlantis/atlantis/server/events/vcs"
 	"github.com/runatlantis/atlantis/server/logging"
+	"github.com/runatlantis/atlantis/server/logging/fields"
 	"github.com/runatlantis/atlantis/server/recovery"
 	"github.com/uber-go/tally"
 	gitlab "github.com/xanzy/go-gitlab"
@@ -129,8 +131,10 @@ type DefaultCommandRunner struct {
 	CommentCommandRunnerByCmd     map[command.Name]command.Runner
 	Drainer                       *Drainer
 	PreWorkflowHooksCommandRunner PreWorkflowHooksCommandRunner
+	CommitStatusUpdater           CommitStatusUpdater
 	PullStatusFetcher             PullStatusFetcher
 	StaleCommandChecker           StaleCommandChecker
+	Logger                        logging.Logger
 }
 
 // RunAutoplanCommand runs plan and policy_checks when a pull request is opened or updated.
@@ -176,10 +180,11 @@ func (c *DefaultCommandRunner) RunAutoplanCommand(logger logging.SimpleLogging,
 		return
 	}
 
-	err = c.PreWorkflowHooksCommandRunner.RunPreHooks(ctx)
-
-	if err != nil {
-		ctx.Log.Errorf("Error running pre-workflow hooks %s. Proceeding with %s command.", err, command.Plan)
+	if err := c.PreWorkflowHooksCommandRunner.RunPreHooks(context.TODO(), ctx); err != nil {
+		//TODO: thread context and use related logging methods.
+		c.Logger.ErrorContext(context.TODO(), "Error running pre-workflow hooks", fields.PullRequestWithErr(pull, err))
+		c.CommitStatusUpdater.UpdateCombined(context.TODO(), ctx.HeadRepo, ctx.Pull, models.FailedCommitStatus, command.Plan)
+		return
 	}
 
 	autoPlanRunner := buildCommentCommandRunner(c, command.Plan)
@@ -243,10 +248,11 @@ func (c *DefaultCommandRunner) RunCommentCommand(logger logging.SimpleLogging, b
 		return
 	}
 
-	err = c.PreWorkflowHooksCommandRunner.RunPreHooks(ctx)
-
-	if err != nil {
-		ctx.Log.Errorf("Error running pre-workflow hooks %s. Proceeding with %s command.", err, cmd.Name.String())
+	if err := c.PreWorkflowHooksCommandRunner.RunPreHooks(context.TODO(), ctx); err != nil {
+		//TODO: thread context and use related logging methods.
+		c.Logger.ErrorContext(context.TODO(), "Error running pre-workflow hooks", fields.PullRequestWithErr(pull, err))
+		c.CommitStatusUpdater.UpdateCombined(context.TODO(), ctx.HeadRepo, ctx.Pull, models.FailedCommitStatus, cmd.Name)
+		return
 	}
 
 	cmdRunner := buildCommentCommandRunner(c, cmd.CommandName())

server/events/command_runner_test.go

@@ -189,7 +189,7 @@ func setup(t *testing.T) *vcsmocks.MockClient {
 
 	preWorkflowHooksCommandRunner = mocks.NewMockPreWorkflowHooksCommandRunner()
 
-	When(preWorkflowHooksCommandRunner.RunPreHooks(matchers.AnyPtrToEventsCommandContext())).ThenReturn(nil)
+	When(preWorkflowHooksCommandRunner.RunPreHooks(matchers.AnyContextContext(), matchers.AnyPtrToEventsCommandContext())).ThenReturn(nil)
 
 	globalCfg := valid.NewGlobalCfgFromArgs(valid.GlobalCfgArgs{})
 	scope, _, _ := metrics.NewLoggingScope(logger, "atlantis")
@@ -199,6 +199,7 @@ func setup(t *testing.T) *vcsmocks.MockClient {
 	ch = events.DefaultCommandRunner{
 		VCSClient:                     vcsClient,
 		CommentCommandRunnerByCmd:     commentCommandRunnerByCmd,
+		Logger:                        logging.NewNoopCtxLogger(t),
 		EventParser:                   eventParsing,
 		GithubPullGetter:              githubGetter,
 		GitlabMergeRequestGetter:      gitlabGetter,
@@ -211,6 +212,7 @@ func setup(t *testing.T) *vcsmocks.MockClient {
 		PreWorkflowHooksCommandRunner: preWorkflowHooksCommandRunner,
 		PullStatusFetcher:             defaultBoltDB,
 		StaleCommandChecker:           staleCommandChecker,
+		CommitStatusUpdater:           commitUpdater,
 	}
 	return vcsClient
 }
@@ -299,6 +301,32 @@ func TestRunCommentCommand_ForkPRDisabled_SilenceEnabled(t *testing.T) {
 	vcsClient.VerifyWasCalled(Never()).CreateComment(matchers.AnyModelsRepo(), AnyInt(), AnyString(), AnyString())
 }
 
+func TestRunCommentCommand_PreWorkflowHookError(t *testing.T) {
+	t.Log("if pre workflow hook errors out stop the execution")
+	for _, cmd := range []command.Name{command.Plan, command.Apply} {
+		t.Run(cmd.String(), func(t *testing.T) {
+			RegisterMockTestingT(t)
+			_ = setup(t)
+			log := logging.NewNoopLogger(t)
+			var pull github.PullRequest
+			modelPull := models.PullRequest{BaseRepo: fixtures.GithubRepo, Num: fixtures.Pull.Num, State: models.OpenPullState}
+			preWorkflowHooksCommandRunner = mocks.NewMockPreWorkflowHooksCommandRunner()
+
+			When(githubGetter.GetPullRequest(fixtures.GithubRepo, fixtures.Pull.Num)).ThenReturn(&pull, nil)
+			When(eventParsing.ParseGithubPull(&pull)).ThenReturn(modelPull, modelPull.BaseRepo, fixtures.GithubRepo, nil)
+			When(staleCommandChecker.CommandIsStale(matchers.AnyPtrToModelsCommandContext())).ThenReturn(false)
+			When(preWorkflowHooksCommandRunner.RunPreHooks(matchers.AnyContextContext(), matchers.AnyPtrToEventsCommandContext())).ThenReturn(fmt.Errorf("catastrophic error"))
+
+			ch.PreWorkflowHooksCommandRunner = preWorkflowHooksCommandRunner
+
+			ch.RunCommentCommand(log, fixtures.GithubRepo, nil, nil, fixtures.User, fixtures.Pull.Num, &command.Comment{Name: cmd}, time.Now())
+			_, _, _, status, cmdName := commitUpdater.VerifyWasCalledOnce().UpdateCombined(matchers.AnyContextContext(), matchers.AnyModelsRepo(), matchers.AnyModelsPullRequest(), matchers.AnyModelsCommitStatus(), matchers.AnyCommandName()).GetCapturedArguments()
+			Equals(t, models.FailedCommitStatus, status)
+			Equals(t, cmd, cmdName)
+		})
+	}
+}
+
 func TestRunCommentCommandPlan_NoProjects_SilenceEnabled(t *testing.T) {
 	t.Log("if a plan command is run on a pull request and SilenceNoProjects is enabled and we are silencing all comments if the modified files don't have a matching project")
 	vcsClient := setup(t)
@@ -534,6 +562,28 @@ func TestRunUnlockCommandFail_VCSComment(t *testing.T) {
 	vcsClient.VerifyWasCalledOnce().CreateComment(fixtures.GithubRepo, fixtures.Pull.Num, "Failed to delete PR locks", "unlock")
 }
 
+func TestRunAutoplanCommand_PreWorkflowHookError(t *testing.T) {
+	t.Log("if pre workflow hook errors out stop the execution")
+	setup(t)
+	log := logging.NewNoopLogger(t)
+	var pull github.PullRequest
+	modelPull := models.PullRequest{BaseRepo: fixtures.GithubRepo, Num: fixtures.Pull.Num, State: models.OpenPullState}
+	preWorkflowHooksCommandRunner = mocks.NewMockPreWorkflowHooksCommandRunner()
+
+	When(githubGetter.GetPullRequest(fixtures.GithubRepo, fixtures.Pull.Num)).ThenReturn(&pull, nil)
+	When(eventParsing.ParseGithubPull(&pull)).ThenReturn(modelPull, modelPull.BaseRepo, fixtures.GithubRepo, nil)
+	When(staleCommandChecker.CommandIsStale(matchers.AnyPtrToModelsCommandContext())).ThenReturn(false)
+	When(preWorkflowHooksCommandRunner.RunPreHooks(matchers.AnyContextContext(), matchers.AnyPtrToEventsCommandContext())).ThenReturn(fmt.Errorf("catastrophic error"))
+	When(projectCommandRunner.Plan(matchers.AnyCommandProjectContext())).ThenReturn(command.ProjectResult{PlanSuccess: &models.PlanSuccess{}})
+
+	ch.PreWorkflowHooksCommandRunner = preWorkflowHooksCommandRunner
+
+	ch.RunAutoplanCommand(log, fixtures.GithubRepo, fixtures.GithubRepo, fixtures.Pull, fixtures.User, time.Now())
+	_, _, _, status, cmdName := commitUpdater.VerifyWasCalledOnce().UpdateCombined(matchers.AnyContextContext(), matchers.AnyModelsRepo(), matchers.AnyModelsPullRequest(), matchers.AnyModelsCommitStatus(), matchers.AnyCommandName()).GetCapturedArguments()
+	Equals(t, models.FailedCommitStatus, status)
+	Equals(t, command.Plan, cmdName)
+}
+
 // Test that if one plan fails and we are using automerge, that
 // we delete the plans.
 func TestRunAutoplanCommand_DeletePlans(t *testing.T) {

server/events/pre_workflow_hooks_command_runner.go

@@ -1,6 +1,9 @@
 package events
 
 import (
+	"context"
+
+	"github.com/pkg/errors"
 	"github.com/runatlantis/atlantis/server/core/config/valid"
 	"github.com/runatlantis/atlantis/server/core/runtime"
 	"github.com/runatlantis/atlantis/server/events/command"
@@ -11,7 +14,7 @@ import (
 //go:generate pegomock generate -m --use-experimental-model-gen --package mocks -o mocks/mock_pre_workflows_hooks_command_runner.go PreWorkflowHooksCommandRunner
 
 type PreWorkflowHooksCommandRunner interface {
-	RunPreHooks(ctx *command.Context) error
+	RunPreHooks(ctx context.Context, cmdCtx *command.Context) error
 }
 
 // DefaultPreWorkflowHooksCommandRunner is the first step when processing a workflow hook commands.
@@ -25,13 +28,14 @@ type DefaultPreWorkflowHooksCommandRunner struct {
 
 // RunPreHooks runs pre_workflow_hooks when PR is opened or updated.
 func (w *DefaultPreWorkflowHooksCommandRunner) RunPreHooks(
-	ctx *command.Context,
+	ctx context.Context,
+	cmdCtx *command.Context,
 ) error {
-	pull := ctx.Pull
+	pull := cmdCtx.Pull
 	baseRepo := pull.BaseRepo
-	headRepo := ctx.HeadRepo
-	user := ctx.User
-	log := ctx.Log
+	headRepo := cmdCtx.HeadRepo
+	user := cmdCtx.User
+	log := cmdCtx.Log
 
 	preWorkflowHooks := make([]*valid.PreWorkflowHook, 0)
 	for _, repo := range w.GlobalCfg.Repos {
@@ -49,14 +53,14 @@ func (w *DefaultPreWorkflowHooksCommandRunner) RunPreHooks(
 
 	unlockFn, err := w.WorkingDirLocker.TryLock(baseRepo.FullName, pull.Num, DefaultWorkspace)
 	if err != nil {
-		return err
+		return errors.Wrap(err, "locking working dir")
 	}
 	log.Debugf("got workspace lock")
 	defer unlockFn()
 
 	repoDir, _, err := w.WorkingDir.Clone(log, headRepo, pull, DefaultWorkspace)
 	if err != nil {
-		return err
+		return errors.Wrap(err, "cloning repository")
 	}
 
 	err = w.runHooks(
@@ -71,20 +75,20 @@ func (w *DefaultPreWorkflowHooksCommandRunner) RunPreHooks(
 		preWorkflowHooks, repoDir)
 
 	if err != nil {
-		return err
+		return errors.Wrap(err, "running pre workflow hooks")
 	}
 
 	return nil
 }
 
 func (w *DefaultPreWorkflowHooksCommandRunner) runHooks(
-	ctx models.PreWorkflowHookCommandContext,
+	cmdCtx models.PreWorkflowHookCommandContext,
 	preWorkflowHooks []*valid.PreWorkflowHook,
 	repoDir string,
 ) error {
 
 	for _, hook := range preWorkflowHooks {
-		_, err := w.PreWorkflowHookRunner.Run(ctx, hook.RunCommand, repoDir)
+		_, err := w.PreWorkflowHookRunner.Run(cmdCtx, hook.RunCommand, repoDir)
 
 		if err != nil {
 			return err

server/events/pre_workflow_hooks_command_runner_test.go

@@ -1,6 +1,7 @@
 package events_test
 
 import (
+	"context"
 	"errors"
 	"testing"
 
@@ -97,7 +98,7 @@ func TestRunPreHooks_Clone(t *testing.T) {
 		When(whWorkingDir.Clone(log, fixtures.GithubRepo, newPull, events.DefaultWorkspace)).ThenReturn(repoDir, false, nil)
 		When(whPreWorkflowHookRunner.Run(pCtx, testHook.RunCommand, repoDir)).ThenReturn(result, nil)
 
-		err := wh.RunPreHooks(ctx)
+		err := wh.RunPreHooks(context.TODO(), ctx)
 
 		Ok(t, err)
 		whPreWorkflowHookRunner.VerifyWasCalledOnce().Run(pCtx, testHook.RunCommand, repoDir)
@@ -124,7 +125,7 @@ func TestRunPreHooks_Clone(t *testing.T) {
 
 		wh.GlobalCfg = globalCfg
 
-		err := wh.RunPreHooks(ctx)
+		err := wh.RunPreHooks(context.TODO(), ctx)
 
 		Ok(t, err)
 
@@ -150,7 +151,7 @@ func TestRunPreHooks_Clone(t *testing.T) {
 
 		When(whWorkingDirLocker.TryLock(fixtures.GithubRepo.FullName, newPull.Num, events.DefaultWorkspace)).ThenReturn(func() {}, errors.New("some error"))
 
-		err := wh.RunPreHooks(ctx)
+		err := wh.RunPreHooks(context.TODO(), ctx)
 
 		Assert(t, err != nil, "error not nil")
 		whWorkingDir.VerifyWasCalled(Never()).Clone(log, fixtures.GithubRepo, newPull, events.DefaultWorkspace)
@@ -181,7 +182,7 @@ func TestRunPreHooks_Clone(t *testing.T) {
 		When(whWorkingDirLocker.TryLock(fixtures.GithubRepo.FullName, newPull.Num, events.DefaultWorkspace)).ThenReturn(unlockFn, nil)
 		When(whWorkingDir.Clone(log, fixtures.GithubRepo, newPull, events.DefaultWorkspace)).ThenReturn(repoDir, false, errors.New("some error"))
 
-		err := wh.RunPreHooks(ctx)
+		err := wh.RunPreHooks(context.TODO(), ctx)
 
 		Assert(t, err != nil, "error not nil")
 
@@ -214,7 +215,7 @@ func TestRunPreHooks_Clone(t *testing.T) {
 		When(whWorkingDir.Clone(log, fixtures.GithubRepo, newPull, events.DefaultWorkspace)).ThenReturn(repoDir, false, nil)
 		When(whPreWorkflowHookRunner.Run(pCtx, testHook.RunCommand, repoDir)).ThenReturn(result, errors.New("some error"))
 
-		err := wh.RunPreHooks(ctx)
+		err := wh.RunPreHooks(context.TODO(), ctx)
 
 		Assert(t, err != nil, "error not nil")
 		Assert(t, *unlockCalled == true, "unlock function called")