Skip to content

Commit

Permalink
Add additional logging for notification conditions (#516)
Browse files Browse the repository at this point in the history
- Extracted Condition interface that let's us log both if the condition
  was met and if the user preference allowed the notification to be sent
- Conditions that have interesting logic are unit-tested
- Moves to the message supplier style of logging, which is not invoked
  unless that level of logging is enabled
- Introduces a build key format - [ProjectFullDisplayName #<build>] to
  better indicate which build the messaging is coming from
- Introduce SlackFactory in ActiveNotifier instead of passing in the
  dependencies to create a slack factory method
- Introduce SlackNotificationsLogger - which writes to the system log
  with the build key embedded, and writes info-level messages to the
  build log with the plugin name embedded
  • Loading branch information
sghill authored and timja committed Feb 16, 2019
1 parent d5ceadd commit b3a9261
Show file tree
Hide file tree
Showing 26 changed files with 853 additions and 76 deletions.
110 changes: 53 additions & 57 deletions src/main/java/jenkins/plugins/slack/ActiveNotifier.java
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,6 @@
import hudson.Util;
import hudson.model.AbstractBuild;
import hudson.model.AbstractProject;
import hudson.model.BuildListener;
import hudson.model.Cause;
import hudson.model.CauseAction;
import hudson.model.Result;
Expand All @@ -15,57 +14,53 @@
import hudson.tasks.test.AbstractTestResultAction;
import hudson.tasks.test.TestResult;
import hudson.triggers.SCMTrigger;
import hudson.util.LogTaskListener;
import jenkins.model.Jenkins;
import jenkins.plugins.slack.decisions.Context;
import jenkins.plugins.slack.decisions.NotificationConditions;
import jenkins.plugins.slack.logging.BuildAwareLogger;
import jenkins.plugins.slack.logging.BuildKey;
import org.apache.commons.collections.CollectionUtils;
import org.apache.commons.lang.StringUtils;
import org.jenkinsci.plugins.displayurlapi.DisplayURLProvider;
import org.jenkinsci.plugins.tokenmacro.MacroEvaluationException;
import org.jenkinsci.plugins.tokenmacro.TokenMacro;

import java.io.IOException;
import java.text.MessageFormat;
import java.util.ArrayList;
import java.util.HashSet;
import java.util.LinkedList;
import java.util.List;
import java.util.Set;
import java.util.logging.Logger;
import java.util.function.Function;
import java.util.regex.Matcher;
import java.util.regex.Pattern;

import static java.util.logging.Level.INFO;
import static java.util.logging.Level.SEVERE;

@SuppressWarnings("rawtypes")
public class ActiveNotifier implements FineGrainedNotifier {

private static final Logger logger = Logger.getLogger(SlackNotifier.class.getName());

SlackNotifier notifier;
BuildListener listener;
private final Function<AbstractBuild<?, ?>, SlackService> slackFactory;
private final BuildAwareLogger log;
private final TokenExpander tokenExpander;

public ActiveNotifier(SlackNotifier notifier, BuildListener listener) {
public ActiveNotifier(SlackNotifier notifier, Function<AbstractBuild<?, ?>, SlackService> slackFactory, BuildAwareLogger log, TokenExpander tokenExpander) {
super();
this.notifier = notifier;
this.listener = listener;
}

private SlackService getSlack(AbstractBuild r) {
return notifier.newSlackService(r, listener);
this.slackFactory = slackFactory;
this.log = log;
this.tokenExpander = tokenExpander;
}

public void deleted(AbstractBuild r) {
}

public void started(AbstractBuild build) {
String key = BuildKey.format(build);

CauseAction causeAction = build.getAction(CauseAction.class);

if (causeAction != null) {
Cause scmCause = causeAction.findCause(SCMTrigger.SCMTriggerCause.class);
if (scmCause == null) {
MessageBuilder message = new MessageBuilder(notifier, build);
log.debug(key, "was not caused by SCM Trigger");
MessageBuilder message = new MessageBuilder(notifier, build, log, tokenExpander);
message.append(causeAction.getCauses().get(0).getShortDescription());
message.appendOpenLink();
if (notifier.getIncludeCustomMessage()) {
Expand All @@ -75,6 +70,8 @@ public void started(AbstractBuild build) {
// Cause was found, exit early to prevent double-message
return;
}
} else {
log.debug(key, "did not have a cause action");
}

String changes = getChanges(build, notifier.getIncludeCustomMessage());
Expand All @@ -88,15 +85,16 @@ public void started(AbstractBuild build) {
private void notifyStart(AbstractBuild build, String message) {
AbstractProject<?, ?> project = build.getProject();
AbstractBuild<?, ?> lastBuild = project.getLastBuild();
SlackService slack = slackFactory.apply(build);
if (lastBuild != null) {
AbstractBuild<?, ?> previousBuild = lastBuild.getPreviousCompletedBuild();
if (previousBuild == null) {
getSlack(build).publish(message, "good");
slack.publish(message, "good");
} else {
getSlack(build).publish(message, getBuildColor(previousBuild));
slack.publish(message, getBuildColor(previousBuild));
}
} else {
getSlack(build).publish(message, "good");
slack.publish(message, "good");
}
}

Expand All @@ -114,40 +112,34 @@ public void finalized(AbstractBuild r) {
notifier.getIncludeFailedTests(), notifier.getIncludeCustomMessage());
if (notifier.getCommitInfoChoice().showAnything()) {
message = message + "\n" + getCommitList(r);
}
getSlack(r).publish(message, getBuildColor(r));
}
slackFactory.apply(r).publish(message, getBuildColor(r));
}
}
}

public void completed(AbstractBuild r) {
String key = BuildKey.format(r);
AbstractProject<?, ?> project = r.getProject();
Result result = r.getResult();
AbstractBuild<?, ?> previousBuild = project.getLastBuild();
if (null != previousBuild) {
do {
previousBuild = previousBuild.getPreviousCompletedBuild();
} while (null != previousBuild && previousBuild.getResult() == Result.ABORTED);
Result previousResult = (null != previousBuild) ? previousBuild.getResult() : Result.SUCCESS;
if ((result == Result.ABORTED && notifier.getNotifyAborted())
|| (result == Result.FAILURE //notify only on single failed build
&& previousResult != Result.FAILURE
&& notifier.getNotifyFailure())
|| (result == Result.FAILURE //notify only on repeated failures
&& previousResult == Result.FAILURE
&& notifier.getNotifyRepeatedFailure())
|| (result == Result.NOT_BUILT && notifier.getNotifyNotBuilt())
|| (result == Result.SUCCESS
&& (previousResult == Result.FAILURE || previousResult == Result.UNSTABLE)
&& notifier.getNotifyBackToNormal())
|| (result == Result.SUCCESS && notifier.getNotifySuccess())
|| (result == Result.UNSTABLE && notifier.getNotifyUnstable())) {
if (null != previousBuild) {
log.info(key, "found #%d as previous completed, non-aborted build", previousBuild.getNumber());
} else {
log.debug(key, "did not find previous completed, non-aborted build");
}

NotificationConditions conditions = NotificationConditions.create(notifier, log);
if (conditions.test(new Context(r, previousBuild))) {
String message = getBuildStatusMessage(r, notifier.getIncludeTestSummary(),
notifier.getIncludeFailedTests(), notifier.getIncludeCustomMessage());
if (notifier.getCommitInfoChoice().showAnything()) {
message = message + "\n" + getCommitList(r);
}
getSlack(r).publish(message, getBuildColor(r));
slackFactory.apply(r).publish(message, getBuildColor(r));
}
}
}
Expand Down Expand Up @@ -178,30 +170,31 @@ private Set<String> getFailedTestIds(AbstractBuild currentBuild) {
}

String getChanges(AbstractBuild r, boolean includeCustomMessage) {
String key = BuildKey.format(r);
if (!r.hasChangeSetComputed()) {
logger.info("No change set computed...");
log.debug(key, "did not have change set computed");
return null;
}
ChangeLogSet changeSet = r.getChangeSet();
List<Entry> entries = new LinkedList<>();
Set<AffectedFile> files = new HashSet<>();
for (Object o : changeSet.getItems()) {
Entry entry = (Entry) o;
logger.info("Entry " + o);
log.debug(key, "adding changeset entry: %s", o);
entries.add(entry);
if (CollectionUtils.isNotEmpty(entry.getAffectedFiles())) {
files.addAll(entry.getAffectedFiles());
}
}
if (entries.isEmpty()) {
logger.info("Empty change...");
log.debug(key, "did not have entries in changeset");
return null;
}
Set<String> authors = new HashSet<>();
for (Entry entry : entries) {
authors.add(entry.getAuthor().getDisplayName());
}
MessageBuilder message = new MessageBuilder(notifier, r);
MessageBuilder message = new MessageBuilder(notifier, r, log, tokenExpander);
message.append("Started by changes from ");
message.append(StringUtils.join(authors, ", "));
message.append(" (");
Expand All @@ -215,15 +208,16 @@ String getChanges(AbstractBuild r, boolean includeCustomMessage) {
}

String getCommitList(AbstractBuild r) {
String buildKey = BuildKey.format(r);
ChangeLogSet changeSet = r.getChangeSet();
List<Entry> entries = new LinkedList<>();
for (Object o : changeSet.getItems()) {
Entry entry = (Entry) o;
logger.info("Entry " + o);
log.debug(buildKey, "adding changeset entry: %s", o);
entries.add(entry);
}
if (entries.isEmpty()) {
logger.info("Empty change...");
log.debug(buildKey, "did not have entries in changeset");
Cause.UpstreamCause c = (Cause.UpstreamCause)r.getCause(Cause.UpstreamCause.class);
if (c == null) {
return "No Changes.";
Expand All @@ -248,7 +242,7 @@ String getCommitList(AbstractBuild r) {
}
commits.add(commit.toString());
}
MessageBuilder message = new MessageBuilder(notifier, r);
MessageBuilder message = new MessageBuilder(notifier, r, log, tokenExpander);
message.append("Changes:\n- ");
message.append(StringUtils.join(commits, "\n- "));
return message.toString();
Expand All @@ -266,7 +260,7 @@ static String getBuildColor(AbstractBuild r) {
}

String getBuildStatusMessage(AbstractBuild r, boolean includeTestSummary, boolean includeFailedTests, boolean includeCustomMessage) {
MessageBuilder message = new MessageBuilder(notifier, r);
MessageBuilder message = new MessageBuilder(notifier, r, log, tokenExpander);
message.appendStatusMessage();
message.appendDuration();
message.appendOpenLink();
Expand Down Expand Up @@ -298,12 +292,18 @@ public static class MessageBuilder {

private StringBuilder message;
private SlackNotifier notifier;
private final BuildAwareLogger log;
private final String buildKey;
private final TokenExpander tokenExpander;
private AbstractBuild build;

public MessageBuilder(SlackNotifier notifier, AbstractBuild build) {
public MessageBuilder(SlackNotifier notifier, AbstractBuild build, BuildAwareLogger log, TokenExpander tokenExpander) {
this.notifier = notifier;
this.log = log;
this.tokenExpander = tokenExpander;
this.message = new StringBuilder();
this.build = build;
this.buildKey = BuildKey.format(build);
startMessage();
}

Expand Down Expand Up @@ -464,13 +464,9 @@ public MessageBuilder appendCustomMessage(Result buildResult) {
if (customMessage == null || customMessage.isEmpty()) {
customMessage = notifier.getCustomMessage();
}
try {
String replaced = TokenMacro.expandAll(build, new LogTaskListener(logger, INFO), customMessage, false, null);
message.append("\n");
message.append(replaced);
} catch (MacroEvaluationException | IOException | InterruptedException e) {
logger.log(SEVERE, e.getMessage(), e);
}
String replaced = tokenExpander.expand(customMessage, build);
message.append("\n");
message.append(replaced);
return this;
}

Expand Down
29 changes: 29 additions & 0 deletions src/main/java/jenkins/plugins/slack/JenkinsTokenExpander.java
Original file line number Diff line number Diff line change
@@ -0,0 +1,29 @@
package jenkins.plugins.slack;

import hudson.model.AbstractBuild;
import hudson.model.TaskListener;
import org.jenkinsci.plugins.tokenmacro.MacroEvaluationException;
import org.jenkinsci.plugins.tokenmacro.TokenMacro;

import java.io.IOException;
import java.util.logging.Level;
import java.util.logging.Logger;

public class JenkinsTokenExpander implements TokenExpander {
private static final Logger logger = Logger.getLogger(JenkinsTokenExpander.class.getName());
private final TaskListener listener;

public JenkinsTokenExpander(TaskListener listener) {
this.listener = listener;
}

@Override
public String expand(String template, AbstractBuild<?, ?> build) {
try {
return TokenMacro.expandAll(build, listener, template, false, null);
} catch (MacroEvaluationException | IOException | InterruptedException e) {
logger.log(Level.SEVERE, "Failed to process custom message", e);
return "[UNPROCESSABLE] " + template;
}
}
}
37 changes: 24 additions & 13 deletions src/main/java/jenkins/plugins/slack/SlackNotifier.java
Original file line number Diff line number Diff line change
@@ -1,20 +1,15 @@
package jenkins.plugins.slack;

import com.cloudbees.plugins.credentials.common.StandardCredentials;
import com.cloudbees.plugins.credentials.common.StandardListBoxModel;
import com.cloudbees.plugins.credentials.domains.HostnameRequirement;
import hudson.EnvVars;
import hudson.Extension;
import hudson.ExtensionList;
import hudson.Launcher;
import hudson.init.InitMilestone;
import hudson.init.Initializer;
import hudson.Util;
import hudson.model.AbstractBuild;
import hudson.model.AbstractProject;
import hudson.model.BuildListener;
import hudson.model.Item;
import hudson.model.listeners.ItemListener;
import hudson.security.ACL;
import hudson.tasks.BuildStepDescriptor;
import hudson.tasks.BuildStepMonitor;
Expand All @@ -24,6 +19,9 @@
import hudson.util.ListBoxModel;
import jenkins.model.Jenkins;
import jenkins.plugins.slack.config.GlobalCredentialMigrator;
import jenkins.plugins.slack.logging.BuildAwareLogger;
import jenkins.plugins.slack.logging.BuildKey;
import jenkins.plugins.slack.logging.SlackNotificationsLogger;
import net.sf.json.JSONObject;
import org.apache.commons.lang.StringUtils;
import org.jenkinsci.Symbol;
Expand All @@ -34,8 +32,8 @@
import org.kohsuke.stapler.DataBoundSetter;
import org.kohsuke.stapler.QueryParameter;
import org.kohsuke.stapler.StaplerRequest;
import org.kohsuke.stapler.export.Exported;

import java.util.function.Function;
import java.util.logging.Level;
import java.util.logging.Logger;
import java.util.stream.Stream;
Expand Down Expand Up @@ -440,27 +438,40 @@ public boolean needsToRunAfterFinalized() {

@Override
public boolean perform(AbstractBuild<?, ?> build, Launcher launcher, BuildListener listener) {
logger.info("Performing complete notifications");
new ActiveNotifier(this, listener).completed(build);
String buildKey = BuildKey.format(build);
BuildAwareLogger log = createLogger(listener);
log.debug(buildKey, "Performing complete notifications");
JenkinsTokenExpander tokenExpander = new JenkinsTokenExpander(listener);
new ActiveNotifier(this, slackFactory(listener), log, tokenExpander).completed(build);
if (notifyRegression) {
logger.info("Performing finalize notifications");
new ActiveNotifier(this, listener).finalized(build);
log.debug(buildKey, "Performing finalize notifications");
new ActiveNotifier(this, slackFactory(listener), log, tokenExpander).finalized(build);
}
return true;
}

@Override
public boolean prebuild(AbstractBuild<?, ?> build, BuildListener listener) {
if (startNotification) {
logger.info("Performing start notifications");
new ActiveNotifier(this, listener).started(build);
BuildAwareLogger log = createLogger(listener);
log.debug(BuildKey.format(build), "Performing start notifications");
new ActiveNotifier(this, slackFactory(listener), log, new JenkinsTokenExpander(listener)).started(build);
}
return super.prebuild(build, listener);
}

private Function<AbstractBuild<?, ?>, SlackService> slackFactory(BuildListener listener) {
return b -> newSlackService(b, listener);
}

private static BuildAwareLogger createLogger(BuildListener listener) {
return new SlackNotificationsLogger(logger, listener.getLogger());
}

@Extension @Symbol("slackNotifier")
public static class DescriptorImpl extends BuildStepDescriptor<Publisher> {

public static final String PLUGIN_DISPLAY_NAME = "Slack Notifications";
private String baseUrl;
private String teamDomain;
private String token;
Expand Down Expand Up @@ -600,7 +611,7 @@ SlackService getSlackService(final String baseUrl, final String teamDomain, fina
@Nonnull
@Override
public String getDisplayName() {
return "Slack Notifications";
return PLUGIN_DISPLAY_NAME;
}

public FormValidation doTestConnection(@QueryParameter("baseUrl") final String baseUrl,
Expand Down
Loading

0 comments on commit b3a9261

Please sign in to comment.