feat: Refine the Atlantis Info Message Logging (#5034)

Signed-off-by: Simon Heather <32168619+X-Guardian@users.noreply.github.com>
2026-08-05 07:08:43 +00:00 · 2024-11-19 17:54:55 +00:00
parent b975301b2b
commit e468a23e0b
22 changed files with 119 additions and 85 deletions
--- a/server/controllers/api_controller.go
+++ b/server/controllers/api_controller.go
@@ -154,7 +154,6 @@ func (a *APIController) apiPlan(request *APIRequest, ctx *command.Context) (*com
 	for i, cmd := range cmds {
 		err = a.PreWorkflowHooksCommandRunner.RunPreHooks(ctx, cc[i])
 		if err != nil {
-			ctx.Log.Err("Error running pre-workflow hooks %s.", err)
 			if a.FailOnPreWorkflowHookError {
 				return nil, err
 			}
@@ -163,10 +162,7 @@ func (a *APIController) apiPlan(request *APIRequest, ctx *command.Context) (*com
 		res := a.ProjectPlanCommandRunner.Plan(cmd)
 		projectResults = append(projectResults, res)

-		err = a.PostWorkflowHooksCommandRunner.RunPostHooks(ctx, cc[i])
-		if err != nil {
-			ctx.Log.Err("Error running post-workflow hooks %s.", err)
-		}
+		a.PostWorkflowHooksCommandRunner.RunPostHooks(ctx, cc[i]) // nolint: errcheck
 	}
 	return &command.Result{ProjectResults: projectResults}, nil
 }
@@ -181,7 +177,6 @@ func (a *APIController) apiApply(request *APIRequest, ctx *command.Context) (*co
 	for i, cmd := range cmds {
 		err = a.PreWorkflowHooksCommandRunner.RunPreHooks(ctx, cc[i])
 		if err != nil {
-			ctx.Log.Err("Error running pre-workflow hooks %s.", err)
 			if a.FailOnPreWorkflowHookError {
 				return nil, err
 			}
@@ -190,10 +185,7 @@ func (a *APIController) apiApply(request *APIRequest, ctx *command.Context) (*co
 		res := a.ProjectApplyCommandRunner.Apply(cmd)
 		projectResults = append(projectResults, res)

-		err = a.PostWorkflowHooksCommandRunner.RunPostHooks(ctx, cc[i])
-		if err != nil {
-			ctx.Log.Err("Error running post-workflow hooks %s.", err)
-		}
+		a.PostWorkflowHooksCommandRunner.RunPostHooks(ctx, cc[i]) // nolint: errcheck
 	}
 	return &command.Result{ProjectResults: projectResults}, nil
 }
--- a/server/controllers/events/events_controller.go
+++ b/server/controllers/events/events_controller.go
@@ -19,6 +19,7 @@ import (
 	"html"
 	"io"
 	"net/http"
+	"strconv"
 	"strings"

 	"github.com/google/go-github/v66/github"
@@ -231,7 +232,7 @@ func (e *VCSEventsController) handleBitbucketCloudPost(w http.ResponseWriter, r
 	switch eventType {
 	case bitbucketcloud.PullCreatedHeader, bitbucketcloud.PullUpdatedHeader, bitbucketcloud.PullFulfilledHeader, bitbucketcloud.PullRejectedHeader:
 		e.Logger.Debug("handling as pull request state changed event")
-		e.handleBitbucketCloudPullRequestEvent(w, eventType, body, reqID)
+		e.handleBitbucketCloudPullRequestEvent(e.Logger, w, eventType, body, reqID)
 		return
 	case bitbucketcloud.PullCommentCreatedHeader:
 		e.Logger.Debug("handling as comment created event")
@@ -267,7 +268,7 @@ func (e *VCSEventsController) handleBitbucketServerPost(w http.ResponseWriter, r
 	switch eventType {
 	case bitbucketserver.PullCreatedHeader, bitbucketserver.PullFromRefUpdatedHeader, bitbucketserver.PullMergedHeader, bitbucketserver.PullDeclinedHeader, bitbucketserver.PullDeletedHeader:
 		e.Logger.Debug("handling as pull request state changed event")
-		e.handleBitbucketServerPullRequestEvent(w, eventType, body, reqID)
+		e.handleBitbucketServerPullRequestEvent(e.Logger, w, eventType, body, reqID)
 		return
 	case bitbucketserver.PullCommentCreatedHeader:
 		e.Logger.Debug("handling as comment created event")
@@ -325,33 +326,35 @@ func (e *VCSEventsController) handleGiteaPost(w http.ResponseWriter, r *http.Req
 		}
 	}

+	logger := e.Logger.With("gitea-request-id", reqID)
+
 	// Log the event type for debugging purposes
-	e.Logger.Debug("Received Gitea event %s with ID %s", eventType, reqID)
+	logger.Debug("Received Gitea event %s with ID %s", eventType, reqID)

 	// Depending on the event type, handle the event appropriately
 	switch eventType {
 	case "pull_request_comment":
 		e.HandleGiteaPullRequestCommentEvent(w, body, reqID)
 	case "pull_request":
-		e.Logger.Debug("Handling as pull_request")
-		e.handleGiteaPullRequestEvent(w, body, reqID)
+		logger.Debug("Handling as pull_request")
+		e.handleGiteaPullRequestEvent(logger, w, body, reqID)
 	// Add other case handlers as necessary
 	default:
 		e.respond(w, logging.Debug, http.StatusOK, "Ignoring unsupported Gitea event type: %s %s=%s", eventType, "X-Gitea-Delivery", reqID)
 	}
 }

-func (e *VCSEventsController) handleGiteaPullRequestEvent(w http.ResponseWriter, body []byte, reqID string) {
-	e.Logger.Debug("Entering handleGiteaPullRequestEvent")
+func (e *VCSEventsController) handleGiteaPullRequestEvent(logger logging.SimpleLogging, w http.ResponseWriter, body []byte, reqID string) {
+	logger.Debug("Entering handleGiteaPullRequestEvent")
 	// Attempt to unmarshal the incoming body into the Gitea PullRequest struct
 	var payload gitea.GiteaWebhookPayload
 	if err := json.Unmarshal(body, &payload); err != nil {
 		e.Logger.Err("Failed to unmarshal Gitea webhook payload: %v", err)
-		e.respond(w, logging.Error, http.StatusBadRequest, "Failed to parse request body")
+		e.respond(w, logging.Error, http.StatusBadRequest, "Failed to parse request body: %s %s=%s", err, giteaRequestIDHeader, reqID)
 		return
 	}

-	e.Logger.Debug("Successfully unmarshaled Gitea event")
+	logger.Debug("Successfully unmarshaled Gitea event")

 	// Use the parser function to convert into Atlantis models
 	pull, pullEventType, baseRepo, headRepo, user, err := e.Parser.ParseGiteaPullRequestEvent(payload.PullRequest)
@@ -361,12 +364,14 @@ func (e *VCSEventsController) handleGiteaPullRequestEvent(w http.ResponseWriter,
 		return
 	}

-	e.Logger.Debug("Parsed Gitea event into Atlantis models successfully")
+	logger.Debug("Parsed Gitea event into Atlantis models successfully")

-	logger := e.Logger.With("gitea-request-id", reqID)
-	logger.Debug("Identified Gitea event as type", "type", pullEventType)
-
-	// Call a generic handler for pull request events
+	// Annotate logger with repo and pull/merge request number.
+	logger = logger.With(
+		"repo", baseRepo.FullName,
+		"pull", strconv.Itoa(pull.Num),
+	)
+	logger.Info("Handling Gitea Pull Request '%s' event", pullEventType.String())
 	response := e.handlePullRequestEvent(logger, baseRepo, headRepo, pull, user, pullEventType)

 	e.respond(w, logging.Debug, http.StatusOK, "%s", response.body)
@@ -462,7 +467,7 @@ func (e *VCSEventsController) HandleBitbucketServerCommentEvent(w http.ResponseW
 	e.respond(w, lvl, code, "%s", msg)
 }

-func (e *VCSEventsController) handleBitbucketCloudPullRequestEvent(w http.ResponseWriter, eventType string, body []byte, reqID string) {
+func (e *VCSEventsController) handleBitbucketCloudPullRequestEvent(logger logging.SimpleLogging, w http.ResponseWriter, eventType string, body []byte, reqID string) {
 	pull, baseRepo, headRepo, user, err := e.Parser.ParseBitbucketCloudPullEvent(body)
 	if err != nil {
 		e.respond(w, logging.Error, http.StatusBadRequest, "Error parsing pull data: %s %s=%s", err, bitbucketCloudRequestIDHeader, reqID)
@@ -470,7 +475,14 @@ func (e *VCSEventsController) handleBitbucketCloudPullRequestEvent(w http.Respon
 	}
 	e.Logger.Debug("SHA is %q", pull.HeadCommit)
 	pullEventType := e.Parser.GetBitbucketCloudPullEventType(eventType, pull.HeadCommit, pull.URL)
-	e.Logger.Info("identified event as type %q", pullEventType.String())
+
+	// Annotate logger with repo and pull/merge request number.
+	logger = logger.With(
+		"repo", baseRepo.FullName,
+		"pull", strconv.Itoa(pull.Num),
+	)
+
+	logger.Info("Handling Bitbucket Cloud Pull Request '%s' event", pullEventType.String())
 	resp := e.handlePullRequestEvent(e.Logger, baseRepo, headRepo, pull, user, pullEventType)

 	//TODO: move this to the outer most function similar to github
@@ -485,14 +497,21 @@ func (e *VCSEventsController) handleBitbucketCloudPullRequestEvent(w http.Respon
 	e.respond(w, lvl, code, "%s", msg)
 }

-func (e *VCSEventsController) handleBitbucketServerPullRequestEvent(w http.ResponseWriter, eventType string, body []byte, reqID string) {
+func (e *VCSEventsController) handleBitbucketServerPullRequestEvent(logger logging.SimpleLogging, w http.ResponseWriter, eventType string, body []byte, reqID string) {
 	pull, baseRepo, headRepo, user, err := e.Parser.ParseBitbucketServerPullEvent(body)
 	if err != nil {
 		e.respond(w, logging.Error, http.StatusBadRequest, "Error parsing pull data: %s %s=%s", err, bitbucketServerRequestIDHeader, reqID)
 		return
 	}
 	pullEventType := e.Parser.GetBitbucketServerPullEventType(eventType)
-	e.Logger.Info("identified event as type %q", pullEventType.String())
+
+	// Annotate logger with repo and pull/merge request number.
+	logger = logger.With(
+		"repo", baseRepo.FullName,
+		"pull", strconv.Itoa(pull.Num),
+	)
+
+	logger.Info("Handling Bitbucket Server Pull Request '%s' event", pullEventType.String())
 	resp := e.handlePullRequestEvent(e.Logger, baseRepo, headRepo, pull, user, pullEventType)

 	//TODO: move this to the outer most function similar to github
@@ -523,7 +542,14 @@ func (e *VCSEventsController) HandleGithubPullRequestEvent(logger logging.Simple
 			},
 		}
 	}
-	logger.Debug("identified event as type %q", pullEventType.String())
+
+	// Annotate logger with repo and pull/merge request number.
+	logger = logger.With(
+		"repo", baseRepo.FullName,
+		"pull", strconv.Itoa(pull.Num),
+	)
+
+	logger.Info("Handling GitHub Pull Request '%s' event", pullEventType.String())
 	return e.handlePullRequestEvent(logger, baseRepo, headRepo, pull, user, pullEventType)
 }

@@ -537,7 +563,7 @@ func (e *VCSEventsController) handlePullRequestEvent(logger logging.SimpleLoggin
 			e.commentNotAllowlisted(baseRepo, pull.Num)
 		}

-		err := errors.Errorf("Pull request event from non-allowlisted repo \"%s/%s\"", baseRepo.VCSHost.Hostname, baseRepo.FullName)
+		err := errors.Errorf("Pull request event from non-allowlisted repo '%s/%s'", baseRepo.VCSHost.Hostname, baseRepo.FullName)

 		return HTTPResponse{
 			body: err.Error(),
@@ -567,6 +593,7 @@ func (e *VCSEventsController) handlePullRequestEvent(logger logging.SimpleLoggin
 		}
 	case models.ClosedPullEvent:
 		// If the pull request was closed, we delete locks.
+		logger.Info("Pull request closed, cleaning up...")
 		if err := e.PullCleaner.CleanUpPull(logger, baseRepo, pull); err != nil {
 			return HTTPResponse{
 				body: err.Error(),
@@ -577,7 +604,7 @@ func (e *VCSEventsController) handlePullRequestEvent(logger logging.SimpleLoggin
 				},
 			}
 		}
-		logger.Info("deleted locks and workspace for repo %s, pull %d", baseRepo.FullName, pull.Num)
+		logger.Info("Locks and workspace successfully deleted")
 		return HTTPResponse{
 			body: "Pull request cleaned successfully",
 		}
@@ -603,8 +630,7 @@ func (e *VCSEventsController) handleGitlabPost(w http.ResponseWriter, r *http.Re
 		e.Logger.Debug("handling as comment event")
 		e.HandleGitlabCommentEvent(w, event)
 	case gitlab.MergeEvent:
-		e.Logger.Debug("handling as pull request event")
-		e.HandleGitlabMergeRequestEvent(w, event)
+		e.HandleGitlabMergeRequestEvent(e.Logger, w, event)
 	case gitlab.CommitCommentEvent:
 		e.Logger.Debug("comments on commits are not supported, only comments on merge requests")
 		e.respond(w, logging.Debug, http.StatusOK, "Ignoring comment on commit event")
@@ -650,11 +676,14 @@ func (e *VCSEventsController) handleCommentEvent(logger logging.SimpleLogging, b
 		if len(truncated) > truncateLen {
 			truncated = comment[:truncateLen] + "..."
 		}
+		logger.Debug("Ignoring non-command comment: '%s'", truncated)
 		return HTTPResponse{
 			body: fmt.Sprintf("Ignoring non-command comment: %q", truncated),
 		}
 	}
-	logger.Info("parsed comment as %s", parseResult.Command)
+	if parseResult.Command != nil {
+		logger.Info("Handling '%s' comment", parseResult.Command.Name)
+	}

 	// At this point we know it's a command we're not supposed to ignore, so now
 	// we check if this repo is allowed to run commands in the first place.
@@ -687,18 +716,17 @@ func (e *VCSEventsController) handleCommentEvent(logger logging.SimpleLogging, b
 	// variable to comment back on the pull request.
 	if parseResult.CommentResponse != "" {
 		if err := e.VCSClient.CreateComment(logger, baseRepo, pullNum, parseResult.CommentResponse, ""); err != nil {
-			logger.Err("unable to comment on pull request: %s", err)
+			logger.Err("Unable to comment on pull request: %s", err)
 		}
 		return HTTPResponse{
 			body: "Commenting back on pull request",
 		}
 	}
 	if parseResult.Command.RepoRelDir != "" {
-		logger.Info("Running comment command '%v' on dir '%v' on repo '%v', pull request: %v for user '%v'.",
-			parseResult.Command.Name, parseResult.Command.RepoRelDir, baseRepo.FullName, pullNum, user.Username)
+		logger.Info("Running comment command '%v' on dir '%v' for user '%v'.",
+			parseResult.Command.Name, parseResult.Command.RepoRelDir, user.Username)
 	} else {
-		logger.Info("Running comment command '%v' on repo '%v', pull request: %v for user '%v'.",
-			parseResult.Command.Name, baseRepo.FullName, pullNum, user.Username)
+		logger.Info("Running comment command '%v' for user '%v'.", parseResult.Command.Name, user.Username)
 	}
 	if !e.TestingMode {
 		// Respond with success and then actually execute the command asynchronously.
@@ -718,14 +746,20 @@ func (e *VCSEventsController) handleCommentEvent(logger logging.SimpleLogging, b
 // HandleGitlabMergeRequestEvent will delete any locks associated with the pull
 // request if the event is a merge request closed event. It's exported to make
 // testing easier.
-func (e *VCSEventsController) HandleGitlabMergeRequestEvent(w http.ResponseWriter, event gitlab.MergeEvent) {
+func (e *VCSEventsController) HandleGitlabMergeRequestEvent(logger logging.SimpleLogging, w http.ResponseWriter, event gitlab.MergeEvent) {
 	pull, pullEventType, baseRepo, headRepo, user, err := e.Parser.ParseGitlabMergeRequestEvent(event)
 	if err != nil {
 		e.respond(w, logging.Error, http.StatusBadRequest, "Error parsing webhook: %s", err)
 		return
 	}
-	e.Logger.Info("identified event as type %q", pullEventType.String())
-	resp := e.handlePullRequestEvent(e.Logger, baseRepo, headRepo, pull, user, pullEventType)
+
+	// Annotate logger with repo and pull/merge request number.
+	logger = logger.With(
+		"repo", baseRepo.FullName,
+		"pull", strconv.Itoa(pull.Num),
+	)
+	logger.Info("Processing Gitlab merge request '%s' event", pullEventType.String())
+	resp := e.handlePullRequestEvent(logger, baseRepo, headRepo, pull, user, pullEventType)

 	//TODO: move this to the outer most function similar to github
 	lvl := logging.Debug
--- a/server/core/runtime/models/shell_command_runner.go
+++ b/server/core/runtime/models/shell_command_runner.go
@@ -173,12 +173,12 @@ func (s *ShellCommandRunner) RunCommandAsync(ctx command.ProjectContext) (chan<-

 		// We're done now. Send an error if there was one.
 		if err != nil {
-			err = errors.Wrapf(err, "running '%s %q' in '%s'",
+			err = errors.Wrapf(err, "running '%s' '%s' in '%s'",
 				s.shell.String(), s.command, s.workingDir)
 			log.Err(err.Error())
 			outCh <- Line{Err: err}
 		} else {
-			log.Info("successfully ran '%s %q' in '%s'",
+			log.Info("successfully ran '%s' '%s' in '%s'",
 				s.shell.String(), s.command, s.workingDir)
 		}
 	}()
--- a/server/core/runtime/post_workflow_hook_runner.go
+++ b/server/core/runtime/post_workflow_hook_runner.go
@@ -59,7 +59,7 @@ func (wh DefaultPostWorkflowHookRunner) Run(ctx models.WorkflowHookCommandContex
 	wh.OutputHandler.SendWorkflowHook(ctx, "\n", true)

 	if err != nil {
-		err = fmt.Errorf("%s: running %q in %q: \n%s", err, shell+" "+shellArgs+" "+command, path, out)
+		err = fmt.Errorf("%s: running '%s' in '%s': \n%s", err, shell+" "+shellArgs+" "+command, path, out)
 		ctx.Log.Debug("error: %s", err)
 		return string(out), "", err
 	}
@@ -71,12 +71,12 @@ func (wh DefaultPostWorkflowHookRunner) Run(ctx models.WorkflowHookCommandContex
 		var customStatusErr error
 		customStatusOut, customStatusErr = os.ReadFile(outputFilePath)
 		if customStatusErr != nil {
-			err = fmt.Errorf("%s: running %q in %q: \n%s", err, shell+" "+shellArgs+" "+command, path, out)
+			err = fmt.Errorf("%s: running '%s' in '%s': \n%s", err, shell+" "+shellArgs+" "+command, path, out)
 			ctx.Log.Debug("error: %s", err)
 			return string(out), "", err
 		}
 	}

-	ctx.Log.Info("successfully ran %q in %q", shell+" "+shellArgs+" "+command, path)
+	ctx.Log.Info("Successfully ran '%s' in '%s'", shell+" "+shellArgs+" "+command, path)
 	return string(out), strings.Trim(string(customStatusOut), "\n"), nil
 }
--- a/server/core/runtime/pre_workflow_hook_runner.go
+++ b/server/core/runtime/pre_workflow_hook_runner.go
@@ -77,6 +77,6 @@ func (wh DefaultPreWorkflowHookRunner) Run(ctx models.WorkflowHookCommandContext
 		}
 	}

-	ctx.Log.Info("successfully ran %q in %q", shell+" "+shellArgs+" "+command, path)
+	ctx.Log.Info("Successfully ran '%s' in '%s'", shell+" "+shellArgs+" "+command, path)
 	return string(out), strings.Trim(string(customStatusOut), "\n"), nil
 }
--- a/server/core/terraform/terraform_client.go
+++ b/server/core/terraform/terraform_client.go
@@ -376,11 +376,11 @@ func (c *DefaultClient) RunCommandWithVersion(ctx command.ProjectContext, path s
 	dur := time.Since(start)
 	log := ctx.Log.With("duration", dur)
 	if err != nil {
-		err = errors.Wrapf(err, "running %q in %q", tfCmd, path)
+		err = errors.Wrapf(err, "running '%s' in '%s'", tfCmd, path)
 		log.Err(err.Error())
 		return ansi.Strip(string(out)), err
 	}
-	log.Info("successfully ran %q in %q", tfCmd, path)
+	log.Info("Successfully ran '%s' in '%s'", tfCmd, path)

 	return ansi.Strip(string(out)), nil
 }
--- a/server/core/terraform/terraform_client_internal_test.go
+++ b/server/core/terraform/terraform_client_internal_test.go
@@ -164,7 +164,7 @@ func TestDefaultClient_RunCommandWithVersion_Error(t *testing.T) {
 		"1",
 	}
 	out, err := client.RunCommandWithVersion(ctx, tmp, args, map[string]string{}, nil, "workspace")
-	ErrEquals(t, fmt.Sprintf(`running "echo dying && exit 1" in %q: exit status 1`, tmp), err)
+	ErrEquals(t, fmt.Sprintf(`running 'echo dying && exit 1' in '%s': exit status 1`, tmp), err)
 	// Test that we still get our output.
 	Equals(t, "dying\n", out)
 }
@@ -344,7 +344,7 @@ func TestDefaultClient_RunCommandAsync_ExitOne(t *testing.T) {
 	_, outCh := client.RunCommandAsync(ctx, tmp, []string{"dying", "&&", "exit", "1"}, map[string]string{}, nil, "workspace")

 	out, err := waitCh(outCh)
-	ErrEquals(t, fmt.Sprintf(`running 'sh -c "echo dying && exit 1"' in '%s': exit status 1`, tmp), err)
+	ErrEquals(t, fmt.Sprintf(`running 'sh -c' 'echo dying && exit 1' in '%s': exit status 1`, tmp), err)
 	// Test that we still get our output.
 	Equals(t, "dying", out)

--- a/server/events/command_runner.go
+++ b/server/events/command_runner.go
@@ -159,13 +159,13 @@ func (c *DefaultCommandRunner) RunAutoplanCommand(baseRepo models.Repo, headRepo
 	if c.TeamAllowlistChecker != nil && c.TeamAllowlistChecker.HasRules() {
 		err := c.fetchUserTeams(baseRepo, &user)
 		if err != nil {
-			c.Logger.Err("Unable to fetch user teams: %s", err)
+			log.Err("Unable to fetch user teams: %s", err)
 			return
 		}

 		ok, err := c.checkUserPermissions(baseRepo, user, "plan")
 		if err != nil {
-			c.Logger.Err("Unable to check user permissions: %s", err)
+			log.Err("Unable to check user permissions: %s", err)
 			return
 		}
 		if !ok {
@@ -191,32 +191,32 @@ func (c *DefaultCommandRunner) RunAutoplanCommand(baseRepo models.Repo, headRepo
 	if len(c.DisableAutoplanLabel) > 0 {
 		labels, err := c.VCSClient.GetPullLabels(ctx.Log, baseRepo, pull)
 		if err != nil {
-			ctx.Log.Err("Unable to get pull labels. Proceeding with %s command.", err, command.Plan)
+			ctx.Log.Err("Unable to get VCS pull/merge request labels: %s. Proceeding with autoplan.", err)
 		} else if utils.SlicesContains(labels, c.DisableAutoplanLabel) {
+			ctx.Log.Info("Pull/merge request has disable auto plan label '%s' so not running autoplan.", c.DisableAutoplanLabel)
 			return
 		}
 	}

+	ctx.Log.Info("Running autoplan...")
 	cmd := &CommentCommand{
 		Name: command.Autoplan,
 	}
 	err = c.PreWorkflowHooksCommandRunner.RunPreHooks(ctx, cmd)

 	if err != nil {
-		ctx.Log.Err("Error running pre-workflow hooks %s.", err)
-
 		if c.FailOnPreWorkflowHookError {
 			ctx.Log.Err("'fail-on-pre-workflow-hook-error' set, so not running %s command.", command.Plan)

-			// Update the plan or apply commit status to pending whilst the pre workflow hook is running so that the PR can't be merged.
+			// Update the plan or apply commit status to failed
 			switch cmd.Name {
 			case command.Plan:
 				if err := c.CommitStatusUpdater.UpdateCombined(ctx.Log, ctx.Pull.BaseRepo, ctx.Pull, models.FailedCommitStatus, command.Plan); err != nil {
-					ctx.Log.Warn("unable to update plan commit status: %s", err)
+					ctx.Log.Warn("Unable to update plan commit status: %s", err)
 				}
 			case command.Apply:
 				if err := c.CommitStatusUpdater.UpdateCombined(ctx.Log, ctx.Pull.BaseRepo, ctx.Pull, models.FailedCommitStatus, command.Apply); err != nil {
-					ctx.Log.Warn("unable to update apply commit status: %s", err)
+					ctx.Log.Warn("Unable to update apply commit status: %s", err)
 				}
 			}

@@ -230,11 +230,7 @@ func (c *DefaultCommandRunner) RunAutoplanCommand(baseRepo models.Repo, headRepo

 	autoPlanRunner.Run(ctx, nil)

-	err = c.PostWorkflowHooksCommandRunner.RunPostHooks(ctx, cmd)
-
-	if err != nil {
-		ctx.Log.Err("Error running post-workflow hooks %s.", err)
-	}
+	c.PostWorkflowHooksCommandRunner.RunPostHooks(ctx, cmd) // nolint: errcheck
 }

 // commentUserDoesNotHavePermissions comments on the pull request that the user
@@ -361,12 +357,10 @@ func (c *DefaultCommandRunner) RunCommentCommand(baseRepo models.Repo, maybeHead
 	err = c.PreWorkflowHooksCommandRunner.RunPreHooks(ctx, cmd)

 	if err != nil {
-		ctx.Log.Err("Error running pre-workflow hooks %s.", err)
-
 		if c.FailOnPreWorkflowHookError {
 			ctx.Log.Err("'fail-on-pre-workflow-hook-error' set, so not running %s command.", cmd.Name.String())

-			// Update the plan or apply commit status to pending whilst the pre workflow hook is running so that the PR can't be merged.
+			// Update the plan or apply commit status to failed
 			switch cmd.Name {
 			case command.Plan:
 				if err := c.CommitStatusUpdater.UpdateCombined(ctx.Log, ctx.Pull.BaseRepo, ctx.Pull, models.FailedCommitStatus, command.Plan); err != nil {
@@ -388,11 +382,7 @@ func (c *DefaultCommandRunner) RunCommentCommand(baseRepo models.Repo, maybeHead

 	cmdRunner.Run(ctx, cmd)

-	err = c.PostWorkflowHooksCommandRunner.RunPostHooks(ctx, cmd)
-
-	if err != nil {
-		ctx.Log.Err("Error running post-workflow hooks %s.", err)
-	}
+	c.PostWorkflowHooksCommandRunner.RunPostHooks(ctx, cmd) // nolint: errcheck
 }

 func (c *DefaultCommandRunner) getGithubData(logger logging.SimpleLogging, baseRepo models.Repo, pullNum int) (models.PullRequest, models.Repo, error) {
--- a/server/events/plan_command_runner.go
+++ b/server/events/plan_command_runner.go
@@ -287,7 +287,7 @@ func (p *PlanCommandRunner) run(ctx *command.Context, cmd *CommentCommand) {
 	// This step does not approve any policies that require approval.
 	if len(result.ProjectResults) > 0 &&
 		!(result.HasErrors() || result.PlansDeleted) {
-		ctx.Log.Info("Running policy check for %s", cmd.String())
+		ctx.Log.Info("Running policy check for '%s'", cmd.CommandName())
 		p.policyCheckCommandRunner.Run(ctx, policyCheckCmds)
 	} else if len(projectCmds) == 0 && !cmd.IsForSpecificProject() {
 		// If there were no projects modified, we set successful commit statuses
--- a/server/events/post_workflow_hooks_command_runner.go
+++ b/server/events/post_workflow_hooks_command_runner.go
@@ -50,7 +50,7 @@ func (w *DefaultPostWorkflowHooksCommandRunner) RunPostHooks(ctx *command.Contex
 		return nil
 	}

-	ctx.Log.Debug("post-hooks configured, running...")
+	ctx.Log.Info("Post-workflow hooks configured, running...")

 	unlockFn, err := w.WorkingDirLocker.TryLock(ctx.Pull.BaseRepo.FullName, ctx.Pull.Num, DefaultWorkspace, DefaultRepoRelDir)
 	if err != nil {
@@ -84,6 +84,7 @@ func (w *DefaultPostWorkflowHooksCommandRunner) RunPostHooks(ctx *command.Contex
 		postWorkflowHooks, repoDir)

 	if err != nil {
+		ctx.Log.Err("Error running post-workflow hooks %s.", err)
 		return err
 	}

@@ -146,5 +147,8 @@ func (w *DefaultPostWorkflowHooksCommandRunner) runHooks(
 			ctx.Log.Warn("unable to update post workflow hook status: %s", err)
 		}
 	}
+
+	ctx.Log.Info("Post-workflow hooks completed")
+
 	return nil
 }
--- a/server/events/pre_workflow_hooks_command_runner.go
+++ b/server/events/pre_workflow_hooks_command_runner.go
@@ -50,7 +50,7 @@ func (w *DefaultPreWorkflowHooksCommandRunner) RunPreHooks(ctx *command.Context,
 		return nil
 	}

-	ctx.Log.Debug("pre-hooks configured, running...")
+	ctx.Log.Info("Pre-workflow hooks configured, running...")

 	unlockFn, err := w.WorkingDirLocker.TryLock(ctx.Pull.BaseRepo.FullName, ctx.Pull.Num, DefaultWorkspace, DefaultRepoRelDir)
 	if err != nil {
@@ -96,9 +96,12 @@ func (w *DefaultPreWorkflowHooksCommandRunner) RunPreHooks(ctx *command.Context,
 		preWorkflowHooks, repoDir)

 	if err != nil {
+		ctx.Log.Err("Error running pre-workflow hooks %s.", err)
 		return err
 	}

+	ctx.Log.Info("Pre-workflow hooks completed successfully")
+
 	return nil
 }

--- a/server/events/project_command_builder.go
+++ b/server/events/project_command_builder.go
@@ -522,7 +522,7 @@ func (p *DefaultProjectCommandBuilder) buildAllCommandsByCfg(ctx *command.Contex
 			absProjectDir := filepath.Join(repoDir, mp.Path)
 			pWorkspace, err := p.ProjectFinder.DetermineWorkspaceFromHCL(ctx.Log, absProjectDir)
 			if err != nil {
-				return nil, errors.Wrapf(err, "looking for Terraform Cloud workspace from configuration %s", absProjectDir)
+				return nil, errors.Wrapf(err, "Looking for Terraform Cloud workspace from configuration in '%s'", absProjectDir)
 			}

 			pCfg := p.GlobalCfg.DefaultProjCfg(ctx.Log, ctx.Pull.BaseRepo.ID(), mp.Path, pWorkspace)
--- a/server/events/project_finder.go
+++ b/server/events/project_finder.go
@@ -76,7 +76,7 @@ var cloudBlockSchema = &hcl.BodySchema{
 }

 func (p *DefaultProjectFinder) DetermineWorkspaceFromHCL(log logging.SimpleLogging, absRepoDir string) (string, error) {
-	log.Info("looking for Terraform Cloud workspace from configuration in %q", absRepoDir)
+	log.Info("Looking for Terraform Cloud workspace from configuration in '%s'", absRepoDir)
 	infos, err := os.ReadDir(absRepoDir)
 	if err != nil {
 		return "", err
--- a/server/events/project_locker.go
+++ b/server/events/project_locker.go
@@ -83,7 +83,7 @@ func (p *DefaultProjectLocker) TryLock(log logging.SimpleLogging, pull models.Pu
 			LockFailureReason: failureMsg,
 		}, nil
 	}
-	log.Info("acquired lock with id %q", lockAttempt.LockKey)
+	log.Info("Acquired lock with id '%s'", lockAttempt.LockKey)
 	return &TryLockResponse{
 		LockAcquired: true,
 		UnlockFn: func() error {
--- a/server/events/vcs/azuredevops_client.go
+++ b/server/events/vcs/azuredevops_client.go
@@ -249,6 +249,8 @@ func (g *AzureDevopsClient) UpdateStatus(logger logging.SimpleLogging, repo mode
 		adState = azuredevops.GitFailed.String()
 	}

+	logger.Info("Updating Azure DevOps commit status for '%s' to '%s'", src, adState)
+
 	status := azuredevops.GitPullRequestStatus{}
 	status.Context = GitStatusContextFromSrc(src)
 	status.Description = &description
--- a/server/events/vcs/bitbucketcloud/client.go
+++ b/server/events/vcs/bitbucketcloud/client.go
@@ -181,6 +181,8 @@ func (b *Client) UpdateStatus(logger logging.SimpleLogging, repo models.Repo, pu
 		bbState = "FAILED"
 	}

+	logger.Info("Updating BitBucket commit status for '%s' to '%s'", src, bbState)
+
 	// URL is a required field for bitbucket statuses. We default to the
 	// Atlantis server's URL.
 	if url == "" {
--- a/server/events/vcs/bitbucketserver/client.go
+++ b/server/events/vcs/bitbucketserver/client.go
@@ -238,6 +238,8 @@ func (b *Client) UpdateStatus(logger logging.SimpleLogging, _ models.Repo, pull
 		bbState = "FAILED"
 	}

+	logger.Info("Updating BitBucket commit status for '%s' to '%s'", src, bbState)
+
 	// URL is a required field for bitbucket statuses. We default to the
 	// Atlantis server's URL.
 	if url == "" {
--- a/server/events/vcs/gitea/client.go
+++ b/server/events/vcs/gitea/client.go
@@ -316,7 +316,7 @@ func (c *GiteaClient) UpdateStatus(logger logging.SimpleLogging, repo models.Rep
 		giteaState = gitea.StatusFailure
 	}

-	logger.Debug("Updating status on Gitea pull request %d for '%s' to '%s'", pull.Num, description, state)
+	logger.Info("Updating Gitea check status for '%s' to '%s'", src, state)

 	newStatusOption := gitea.CreateStatusOption{
 		State:       giteaState,
--- a/server/events/vcs/github_client.go
+++ b/server/events/vcs/github_client.go
@@ -909,7 +909,8 @@ func (g *GithubClient) UpdateStatus(logger logging.SimpleLogging, repo models.Re
 	case models.FailedCommitStatus:
 		ghState = "failure"
 	}
-	logger.Debug("Updating status on GitHub pull request %d for '%s' to '%s'", pull.Num, description, ghState)
+
+	logger.Info("Updating GitHub Check status for '%s' to '%s'", src, ghState)

 	status := &github.RepoStatus{
 		State:       github.String(ghState),
--- a/server/events/vcs/gitlab_client.go
+++ b/server/events/vcs/gitlab_client.go
@@ -108,7 +108,7 @@ func NewGitlabClient(hostname string, token string, logger logging.SimpleLogging
 		if err != nil {
 			return nil, err
 		}
-		logger.Info("determined GitLab is running version %s", client.Version.String())
+		logger.Info("GitLab host '%s' is running version %s", client.Client.BaseURL().Host, client.Version.String())
 	}

 	return client, nil
--- a/server/events/vcs/instrumented_client.go
+++ b/server/events/vcs/instrumented_client.go
@@ -215,7 +215,6 @@ func (c *InstrumentedClient) UpdateStatus(logger logging.SimpleLogging, repo mod
 	executionSuccess := scope.Counter(metrics.ExecutionSuccessMetric)
 	executionError := scope.Counter(metrics.ExecutionErrorMetric)

-	logger.Info("updating vcs status")
 	if err := c.Client.UpdateStatus(logger, repo, pull, state, src, description, url); err != nil {
 		executionError.Inc(1)
 		logger.Err("Unable to update status at url: %s, error: %s", url, err.Error())
--- a/server/server.go
+++ b/server/server.go
@@ -317,7 +317,12 @@ func NewServer(userConfig UserConfig, config Config) (*Server, error) {
 		}
 	}

-	logger.Info("Supported VCS Hosts", "hosts", supportedVCSHosts)
+	var supportedVCSHostsStr []string
+	for _, host := range supportedVCSHosts {
+		supportedVCSHostsStr = append(supportedVCSHostsStr, host.String())
+	}
+
+	logger.Info("Supported VCS Hosts: %s", strings.Join(supportedVCSHostsStr, ", "))

 	home, err := homedir.Dir()
 	if err != nil {
@@ -1117,7 +1122,7 @@ func (s *Server) Index(w http.ResponseWriter, _ *http.Request) {
 	}

 	applyCmdLock, err := s.ApplyLocker.CheckApplyLock()
-	s.Logger.Info("Apply Lock: %v", applyCmdLock)
+	s.Logger.Debug("Apply Lock: %v", applyCmdLock)
 	if err != nil {
 		w.WriteHeader(http.StatusServiceUnavailable)
 		fmt.Fprintf(w, "Could not retrieve global apply lock: %s", err)