Improve logging for config loading and usage (#114)

Remove some redundant/confusing logs, clarify messages, and log when we
are skipping branch deletion due to the configuration.

bulldozer/config_fetcher.go

@@ -78,43 +78,37 @@ func (cf *ConfigFetcher) ConfigForPR(ctx context.Context, client *github.Client,
 
 	bytes, err := cf.fetchConfigContents(ctx, client, fc.Owner, fc.Repo, fc.Ref, cf.configurationV1Path)
 	if err == nil && bytes != nil {
-		config, err := cf.unmarshalConfig(bytes)
-		if err != nil {
-			logger.Debug().Msgf("v1 config is invalid")
-		} else {
+		if config, err := cf.unmarshalConfig(bytes); err == nil {
+			logger.Debug().Msgf("Found v1 configuration at %s", cf.configurationV1Path)
 			fc.Config = config
 			return fc, nil
 		}
 	}
+	logger.Debug().Msgf("v1 configuration was missing or invalid, falling back to v0 or server configuration")
 
 	for _, configV0Path := range cf.configurationV0Paths {
-		logger.Debug().Msgf("v1 configuration not found; will attempt fetch v0 %s and unmarshal as v0", configV0Path)
 		bytes, err := cf.fetchConfigContents(ctx, client, fc.Owner, fc.Repo, fc.Ref, configV0Path)
-		if err != nil {
-			continue
-		}
-
-		if bytes == nil {
+		if err != nil || bytes == nil {
 			continue
 		}
 
 		config, err := cf.unmarshalConfigV0(bytes)
 		if err != nil {
 			continue
 		}
-		logger.Debug().Msgf("found v0 configuration at %s with merge method %s", configV0Path, config.Merge.Method)
 
+		logger.Debug().Msgf("Found v0 configuration at %s", configV0Path)
 		fc.Config = config
 		return fc, nil
 	}
 
 	if cf.defaultRepositoryConfig != nil {
-		logger.Debug().Msgf("Default repository config is used as fallback")
+		logger.Debug().Msgf("No repository configuration found, using server-provided default")
 		fc.Config = cf.defaultRepositoryConfig
 		return fc, nil
 	}
 
-	fc.Error = errors.New("Unable to find valid v1 or v0 configuration")
+	fc.Error = errors.New("No configuration found")
 	return fc, nil
 }
 

bulldozer/merge.go

@@ -216,9 +216,8 @@ func MergePR(ctx context.Context, pullCtx pull.Context, merger Merger, mergeConf
 
 			// if head is qualified (contains ":"), PR is from a fork and we don't have delete permission
 			if !strings.ContainsRune(head, ':') {
+				ref := fmt.Sprintf("refs/heads/%s", head)
 				if mergeConfig.DeleteAfterMerge {
-					ref := fmt.Sprintf("refs/heads/%s", head)
-
 					// check other open PRs to make sure that nothing is trying to merge into the ref we're about to delete
 					isTargeted, err := pullCtx.IsTargeted(ctx)
 					if err != nil {
@@ -237,6 +236,8 @@ func MergePR(ctx context.Context, pullCtx pull.Context, merger Merger, mergeConf
 					}
 
 					logger.Info().Msgf("Successfully deleted ref %s on %q", ref, pullCtx.Locator())
+				} else {
+					logger.Debug().Msgf("Not deleting ref %s, delete_after_merge is not enabled", ref)
 				}
 			} else {
 				logger.Debug().Msg("Pull Request is from a fork, not deleting")

server/handler/base.go

@@ -52,18 +52,18 @@ func (b *Base) ProcessPullRequest(ctx context.Context, pullCtx pull.Context, cli
 
 	switch {
 	case bulldozerConfig.Missing():
-		logger.Debug().Msgf("No bulldozer configuration for %q", bulldozerConfig.String())
+		logger.Debug().Msgf("No configuration found for %s", bulldozerConfig)
 	case bulldozerConfig.Invalid():
-		logger.Debug().Msgf("Bulldozer configuration is invalid for %q", bulldozerConfig.String())
+		logger.Warn().Msgf("Configuration is invalid for %s", bulldozerConfig)
 	default:
-		logger.Debug().Msgf("Bulldozer configuration is valid for %q", bulldozerConfig.String())
+		logger.Debug().Msgf("Found valid configuration for %s", bulldozerConfig)
 		config := *bulldozerConfig.Config
+
 		shouldMerge, err := bulldozer.ShouldMergePR(ctx, pullCtx, config.Merge)
 		if err != nil {
 			return errors.Wrap(err, "unable to determine merge status")
 		}
 		if shouldMerge {
-			logger.Debug().Msg("Pull request should be merged")
 			if err := bulldozer.MergePR(ctx, pullCtx, merger, config.Merge); err != nil {
 				return errors.Wrap(err, "failed to merge pull request")
 			}
@@ -83,21 +83,19 @@ func (b *Base) UpdatePullRequest(ctx context.Context, pullCtx pull.Context, clie
 
 	switch {
 	case bulldozerConfig.Missing():
-		logger.Debug().Msgf("No bulldozer configuration for %q", bulldozerConfig.String())
+		logger.Debug().Msgf("No configuration found for %s", bulldozerConfig)
 	case bulldozerConfig.Invalid():
-		logger.Debug().Msgf("Bulldozer configuration is invalid for %q", bulldozerConfig.String())
+		logger.Warn().Msgf("Configuration is invalid for %s", bulldozerConfig)
 	default:
-		logger.Debug().Msgf("Bulldozer configuration is valid for %q", bulldozerConfig.String())
+		logger.Debug().Msgf("Found valid configuration for %s", bulldozerConfig)
 		config := *bulldozerConfig.Config
 
 		shouldUpdate, err := bulldozer.ShouldUpdatePR(ctx, pullCtx, config.Update)
-
 		if err != nil {
 			return errors.Wrap(err, "unable to determine update status")
 		}
 
 		if shouldUpdate {
-			logger.Debug().Msg("Pull request should be updated")
 			if err := bulldozer.UpdatePR(ctx, pullCtx, client, config.Update, baseRef); err != nil {
 				return errors.Wrap(err, "failed to update pull request")
 			}