Improve logging of commit information (#58)

Attach the head SHA of the pull request being evaluated to log messages, log when candidates are removed due to a pushed commit, and log the target ref when posting a commit status.
palantir · Apr 5, 2019 · f3ea4a3 · f3ea4a3
1 parent 8e285ff
commit f3ea4a3
Show file tree

Hide file tree

Showing 6 changed files with 25 additions and 11 deletions.
diff --git a/policy/approval/approve.go b/policy/approval/approve.go
@@ -19,6 +19,7 @@ import (
 	"fmt"
 	"sort"
 	"strings"
+	"time"
 
 	"github.com/pkg/errors"
 	"github.com/rs/zerolog"
@@ -128,15 +129,20 @@ func (r *Rule) IsApproved(ctx context.Context, prctx pull.Context) (bool, string
 		if err != nil {
 			return false, "", err
 		}
-
-		lastCommitTime := commits[len(commits)-1].CreatedAt
+		lastCommit := commits[len(commits)-1]
 
 		var allowedCandidates []*common.Candidate
 		for _, candidate := range candidates {
-			if candidate.CreatedAt.After(lastCommitTime) {
+			if candidate.CreatedAt.After(lastCommit.CreatedAt) {
 				allowedCandidates = append(allowedCandidates, candidate)
 			}
 		}
+
+		log.Debug().Msgf("discarded %d candidates invalidated by push of %s at %s",
+			len(candidates)-len(allowedCandidates),
+			lastCommit.SHA,
+			lastCommit.CreatedAt.Format(time.RFC3339))
+
 		candidates = allowedCandidates
 	}
 

diff --git a/server/handler/base.go b/server/handler/base.go
@@ -106,11 +106,20 @@ func (b *Base) PostStatus(ctx context.Context, client *github.Client, pr *github
 
 func (b *Base) postGitHubRepoStatus(ctx context.Context, client *github.Client, owner, repo, ref string, status *github.RepoStatus) error {
 	logger := zerolog.Ctx(ctx)
-	logger.Info().Msgf("Setting status context=%s state=%s description=%s target_url=%s", status.GetContext(), status.GetState(), status.GetDescription(), status.GetTargetURL())
+	logger.Info().Msgf("Setting %q status on %s to %s: %s", status.GetContext(), ref, status.GetState(), status.GetDescription())
 	_, _, err := client.Repositories.CreateStatus(ctx, owner, repo, ref, status)
 	return err
 }
 
+func (b *Base) PreparePRContext(ctx context.Context, installationID int64, pr *github.PullRequest) (context.Context, zerolog.Logger) {
+	ctx, logger := githubapp.PreparePRContext(ctx, installationID, pr.GetBase().GetRepo(), pr.GetNumber())
+
+	logger = logger.With().Str("github_sha", pr.GetHead().GetSHA()).Logger()
+	ctx = logger.WithContext(ctx)
+
+	return ctx, logger
+}
+
 func (b *Base) Evaluate(ctx context.Context, mbrCtx pull.MembershipContext, client *github.Client, v4client *githubv4.Client, pr *github.PullRequest) error {
 	fetchedConfig, err := b.ConfigFetcher.ConfigForPR(ctx, client, pr)
 	if err != nil {

diff --git a/server/handler/details.go b/server/handler/details.go
@@ -24,7 +24,6 @@ import (
 	"github.com/alexedwards/scs"
 	"github.com/bluekeyes/templatetree"
 	"github.com/google/go-github/github"
-	"github.com/palantir/go-githubapp/githubapp"
 	"github.com/pkg/errors"
 	"goji.io/pat"
 
@@ -107,7 +106,7 @@ func (h *Details) ServeHTTP(w http.ResponseWriter, r *http.Request) error {
 	data.PullRequest = pr
 	data.User = user
 
-	ctx, _ = githubapp.PreparePRContext(ctx, installation.ID, pr.GetBase().GetRepo(), number)
+	ctx, _ = h.PreparePRContext(ctx, installation.ID, pr)
 
 	config, err := h.ConfigFetcher.ConfigForPR(ctx, client, pr)
 	data.PolicyURL = getPolicyURL(pr, config)

diff --git a/server/handler/issue_comment.go b/server/handler/issue_comment.go
@@ -46,10 +46,8 @@ func (h *IssueComment) Handle(ctx context.Context, eventType, deliveryID string,
 	number := event.GetIssue().GetNumber()
 	installationID := githubapp.GetInstallationIDFromEvent(&event)
 
-	ctx, logger := githubapp.PreparePRContext(ctx, installationID, event.GetRepo(), number)
-
 	if !event.GetIssue().IsPullRequest() {
-		logger.Debug().Msg("Issue comment event is not for a pull request")
+		zerolog.Ctx(ctx).Debug().Msg("Issue comment event is not for a pull request")
 		return nil
 	}
 
@@ -68,6 +66,8 @@ func (h *IssueComment) Handle(ctx context.Context, eventType, deliveryID string,
 		return errors.Wrapf(err, "failed to get pull request %s/%s#%d", repo.GetOwner().GetLogin(), repo.GetName(), number)
 	}
 
+	ctx, logger := h.PreparePRContext(ctx, installationID, pr)
+
 	fetchedConfig, err := h.ConfigFetcher.ConfigForPR(ctx, client, pr)
 	if err != nil {
 		return errors.Wrap(err, "failed to fetch configuration")

diff --git a/server/handler/pull_request.go b/server/handler/pull_request.go
@@ -49,7 +49,7 @@ func (h *PullRequest) Handle(ctx context.Context, eventType, deliveryID string,
 		return err
 	}
 
-	ctx, _ = githubapp.PreparePRContext(ctx, installationID, event.GetRepo(), event.GetNumber())
+	ctx, _ = h.PreparePRContext(ctx, installationID, event.GetPullRequest())
 
 	switch event.GetAction() {
 	case "opened", "reopened", "synchronize", "edited":

diff --git a/server/handler/pull_request_review.go b/server/handler/pull_request_review.go
@@ -49,7 +49,7 @@ func (h *PullRequestReview) Handle(ctx context.Context, eventType, deliveryID st
 		return err
 	}
 
-	ctx, _ = githubapp.PreparePRContext(ctx, installationID, event.GetRepo(), event.GetPullRequest().GetNumber())
+	ctx, _ = h.PreparePRContext(ctx, installationID, event.GetPullRequest())
 
 	mbrCtx := NewCrossOrgMembershipContext(ctx, client, event.GetRepo().GetOwner().GetLogin(), h.Installations, h.ClientCreator)
 	return h.Evaluate(ctx, mbrCtx, client, v4client, event.GetPullRequest())