More debug logging around event generation

Trying to determine where the double triggering of serviceMessages is coming from, however it appears to be because TeamCity outputs stdout from a test twice somehow. WebHookServiceMessageHandlerTest#testOutputServiceMessage() has been disabled and a step added to the build in TeamCity instead.
tcplugins · May 25, 2024 · abc9f27 · abc9f27
1 parent de24eb1
commit abc9f27
Show file tree

Hide file tree

Showing 5 changed files with 19 additions and 18 deletions.
diff --git a/tcwebhooks-core/src/main/java/webhook/teamcity/WebHookListener.java b/tcwebhooks-core/src/main/java/webhook/teamcity/WebHookListener.java
@@ -153,11 +153,11 @@ private List<WebHookConfig> getListOfEnabledWebHooks(BuildStateEnum state, Strin
 			WebHookProjectSettings projSettings = mySettings.getSettings(project.getProjectId());
 			if (projSettings.isEnabled()){
 				for (WebHookConfig whc : projSettings.getWebHooksConfigs()){
-					if (Boolean.FALSE.equals(whc.isEnabledForSubProjects()) && !myProject.getProjectId().equals(project.getProjectId())){
+					if (!whc.isEnabledForSubProjects().booleanValue() && !myProject.getProjectId().equals(project.getProjectId())){
 						// Sub-projects are disabled and we are a subproject.
 						if (Loggers.ACTIVITIES.isDebugEnabled()){
 							Loggers.ACTIVITIES.debug(this.getClass().getSimpleName() + ":getListOfEnabledWebHooks() "
-									+ ":: subprojects not enabled. myProject is: " + myProject.getProjectId() + ". webhook project is: " + project.getProjectId());
+									+ ":: subprojects not enabled. myProject is: " + myProject.getProjectId() + ". webhook project is: " + project.getProjectId()+ " : " + whc.getUniqueKey());
 						}
 						continue;
 					}
@@ -167,16 +167,17 @@ private List<WebHookConfig> getListOfEnabledWebHooks(BuildStateEnum state, Strin
 							whc.setProjectExternalId(project.getExternalId());
 							whc.setProjectInternalId(project.getProjectId());
 							configs.add(whc);
+							Loggers.ACTIVITIES.debug("WebHookListener :: WebHook added to list of enabled webhooks. Enabled for " + state.toString() + ".  " + whc.getUrl() + " (" + whc.getPayloadTemplate() + ")" + " : " + whc.getUniqueKey());
 						} else {
-							Loggers.ACTIVITIES.warn("WebHookListener :: No registered Template: " + whc.getPayloadTemplate());
+							Loggers.ACTIVITIES.warn("WebHookListener :: No registered Template: " + whc.getPayloadTemplate() + " for " + whc.getUniqueKey());
 						}
 					} else if (whc.getEnabled().booleanValue() && !whc.isEnabledForBuildState(state)) {
 						if (Loggers.ACTIVITIES.isDebugEnabled()) {
-							Loggers.ACTIVITIES.debug("WebHookListener :: WebHook skipped. Not enabled for " + state.toString() + ".  " + whc.getUrl() + " (" + whc.getPayloadTemplate() + ")");
+							Loggers.ACTIVITIES.debug("WebHookListener :: WebHook skipped. Not enabled for " + state.toString() + ".  " + whc.getUrl() + " (" + whc.getPayloadTemplate() + ")" + " : " + whc.getUniqueKey());
 						}
 					} else {
 						Loggers.ACTIVITIES.debug(this.getClass().getSimpleName()
-								+ ":processBuildEvent() :: WebHook disabled. Will not process " + whc.getUrl() + " (" + whc.getPayloadTemplate() + ")");
+								+ ":processBuildEvent() :: WebHook disabled. Will not process " + whc.getUrl() + " (" + whc.getPayloadTemplate() + ")" + " : " + whc.getUniqueKey());
 					}
 				}
 			} else {

diff --git a/tcwebhooks-core/src/main/java/webhook/teamcity/WebHookServiceMessageHandler.java b/tcwebhooks-core/src/main/java/webhook/teamcity/WebHookServiceMessageHandler.java
@@ -3,6 +3,7 @@
 import java.util.Collections;
 import java.util.List;
 
+import jetbrains.buildServer.log.Loggers;
 import jetbrains.buildServer.messages.BuildMessage1;
 import jetbrains.buildServer.messages.serviceMessages.ServiceMessage;
 import jetbrains.buildServer.messages.serviceMessages.ServiceMessageTranslator;
@@ -21,6 +22,7 @@ public WebHookServiceMessageHandler(WebHookListener webHookListener) {
 	@Override
 	public List<BuildMessage1> translate(SRunningBuild runningBuild, BuildMessage1 originalMessage, ServiceMessage serviceMessage) {
 		myWebHookListener.serviceMessageReceived(runningBuild, serviceMessage.getAttributes());
+		Loggers.SERVER.debug("WebHookServiceMessageHandler :: WebHook service message event received for buildType : " + runningBuild.getBuildTypeExternalId() + " with build id "  + runningBuild.getBuildId());
 
 		return Collections.singletonList(originalMessage);
 	}

diff --git a/tcwebhooks-core/src/main/java/webhook/teamcity/executor/AbstractWebHookExecutor.java b/tcwebhooks-core/src/main/java/webhook/teamcity/executor/AbstractWebHookExecutor.java
@@ -58,8 +58,7 @@ protected AbstractWebHookExecutor(
 
 	@Override
 	public void run() {
-		Loggers.SERVER.debug("AbstractWebHookExecutor :: Starting runner for webhook: " + whc.getUniqueKey() 
-						+  " : " + webhook.getExecutionStats().getTrackingIdAsString());
+		Loggers.SERVER.debug("AbstractWebHookExecutor :: Starting runner for webhook: " + webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey() + " : " + state.getShortName());
 
 		try {
 			this.webhook = getWebHookContent();
@@ -104,8 +103,7 @@ public void run() {
 			errorCallback(new RuntimeException(ex));
 		}
 
-		Loggers.SERVER.debug("AbstractWebHookExecutor :: Finishing runner for webhook: " + whc.getUniqueKey() 
-		+  " : " + webhook.getExecutionStats().getTrackingIdAsString());
+		Loggers.SERVER.debug("AbstractWebHookExecutor :: Finishing runner for webhook: " + webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey() + " : " + state.getShortName());
 	}
 
 

diff --git a/tcwebhooks-core/src/main/java/webhook/teamcity/executor/WebHookThreadingExecutorImpl.java b/tcwebhooks-core/src/main/java/webhook/teamcity/executor/WebHookThreadingExecutorImpl.java
@@ -33,7 +33,7 @@ public class WebHookThreadingExecutorImpl implements WebHookThreadingExecutor {
 	public void execute(WebHook webhook, WebHookConfig whc, SQueuedBuild sQueuedBuild,
 			BuildStateEnum state, String user, String comment, boolean isTest) {
 		Loggers.SERVER.debug("WebHookThreadingExecutorImpl :: About to schedule runner for webhook :: " +
-				webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey());
+				webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey()+ " : " + state.getShortName());
 
 		WebHookRunner runner = webHookRunnerFactory.getRunner(webhook, whc, sQueuedBuild, state, user, comment, isTest);
 		try {
@@ -45,15 +45,15 @@ public void execute(WebHook webhook, WebHookConfig whc, SQueuedBuild sQueuedBuil
 		}
 
 		Loggers.SERVER.debug("WebHookThreadingExecutorImpl :: Finished scheduling runner for webhook :: " +
-				webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey());
+				webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey()+ " : " + state.getShortName());
 	}
 
 	@Override
 	public void execute(WebHook webhook, WebHookConfig whc, BuildStateEnum state,
 			WebHookResponsibilityHolder responsibilityHolder,
 			boolean isTest) {
 		Loggers.SERVER.debug("WebHookThreadingExecutorImpl :: About to schedule runner for webhook :: " +
-				webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey());
+				webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey()+ " : " + state.getShortName());
 
 		WebHookRunner runner = webHookRunnerFactory.getRunner(webhook, whc, state, responsibilityHolder, isTest);
 		try {
@@ -65,15 +65,15 @@ public void execute(WebHook webhook, WebHookConfig whc, BuildStateEnum state,
 		}
 
 		Loggers.SERVER.debug("WebHookThreadingExecutorImpl :: Finished scheduling runner for webhook :: " +
-				webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey());
+				webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey() + " : " + state.getShortName());
 	}
 
 	@Override
 	public void execute(WebHook webhook, WebHookConfig whc, SBuild sBuild, BuildStateEnum state, String user,
 			String comment,
 			boolean isTest, Map<String, String> extraAttributes) {
 		Loggers.SERVER.debug("WebHookThreadingExecutorImpl :: About to schedule runner for webhook :: " +
-				webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey());
+				webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey()+ " : " + state.getShortName());
 
 		WebHookRunner runner = webHookRunnerFactory.getRunner(webhook, whc, sBuild, state, user, comment, isTest,
 				extraAttributes);
@@ -86,7 +86,7 @@ public void execute(WebHook webhook, WebHookConfig whc, SBuild sBuild, BuildStat
 		}
 
 		Loggers.SERVER.debug("WebHookThreadingExecutorImpl :: Finished scheduling runner for webhook :: " +
-				webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey());
+				webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey() + " : " + state.getShortName());
 
 	}
 
@@ -95,7 +95,7 @@ public void execute(WebHook webhook, WebHookConfig whc, SProject sProject,
 			Map<MuteInfo, Collection<STest>> mutedOrUnmutedGroups, BuildStateEnum state, SUser user, boolean isTest) {
 
 		Loggers.SERVER.debug("WebHookSerialExecutorImpl :: About to start runner for webhook :: " +
-				webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey());
+				webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey()+ " : " + state.getShortName());
 
 		WebHookRunner runner = webHookRunnerFactory.getRunner(webhook, whc, sProject, state, mutedOrUnmutedGroups,
 				isTest);
@@ -108,7 +108,7 @@ public void execute(WebHook webhook, WebHookConfig whc, SProject sProject,
 		}
 
 		Loggers.SERVER.debug("WebHookSerialExecutorImpl :: Finished runner for webhook :: " +
-				webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey());
+				webhook.getExecutionStats().getTrackingIdAsString() + " : " + whc.getUniqueKey()+ " : " + state.getShortName());
 
 	}
 

diff --git a/tcwebhooks-core/src/test/java/webhook/teamcity/WebHookServiceMessageHandlerTest.java b/tcwebhooks-core/src/test/java/webhook/teamcity/WebHookServiceMessageHandlerTest.java
@@ -39,7 +39,7 @@ public void testServiceMessageHandlerCalledWebHookListener() throws ParseExcepti
 		Mockito.verify(webhookListener).serviceMessageReceived(runningBuild, Collections.singletonMap("foo", "bar"));
 	}
 
-	@Test
+	//@Test Removed so that TeamCity does not trigger it twice.
 	@SuppressWarnings("java:S2699")
 	public void testOutputServiceMessage() {
 		System.out.println(TEAMCITY_SERVICE_MESSAGE_PREFIX + WebHookServiceMessageHandler.SERVICE_MESSAGE_NAME + " foo='bar'" + TEAMCITY_SERVICE_MESSAGE_SUFFIX);