OZG-6748 KOP-2733 Capture log lines for ITCase

pom.xml

@@ -97,6 +97,11 @@
 			<scope>provided</scope>
 		</dependency>
 
+		<dependency>
+			<groupId>org.apache.logging.log4j</groupId>
+			<artifactId>log4j-core</artifactId>
+		</dependency>
+
 		<!-- Test -->
 		<dependency>
 			<groupId>org.apache.commons</groupId>
@@ -137,7 +142,6 @@
 			<artifactId>snakeyaml</artifactId>
 			<scope>test</scope>
 		</dependency>
-
 	</dependencies>
 
 	<build>
@@ -145,6 +149,29 @@
 			<plugin>
 				<groupId>org.apache.maven.plugins</groupId>
 				<artifactId>maven-compiler-plugin</artifactId>
+				<executions>
+					<execution>
+						<id>log4j2-plugin-processor</id>
+						<goals>
+							<goal>compile</goal>
+							<goal>testCompile</goal>
+						</goals>
+						<phase>process-classes</phase>
+						<configuration>
+							<proc>only</proc>
+							<annotationProcessorPaths>
+								<path>
+									<groupId>org.apache.logging.log4j</groupId>
+									<artifactId>log4j-core</artifactId>
+									<version>${log4j2.version}</version>
+								</path>
+							</annotationProcessorPaths>
+							<annotationProcessors>
+								<processor>org.apache.logging.log4j.core.config.plugins.processor.PluginProcessor</processor>
+							</annotationProcessors>
+						</configuration>
+					</execution>
+				</executions>
 			</plugin>
 			<plugin>
 				<groupId>org.apache.maven.plugins</groupId>

src/main/java/de/ozgcloud/xta/client/XtaClient.java

@@ -32,6 +32,8 @@ public class XtaClient {
 	private final XtaClientConfig config;
 	private final FetchMessageParameterFactory fetchMessageParameterFactory;
 
+	static final String NO_MESSAGE_CLOSED_WARNING = "No message has been closed although more are pending. Try increasing max list items.";
+
 	public static XtaClient from(XtaClientConfig config) throws ClientInitializationException {
 		return XtaClientFactory.from(config).create();
 	}
@@ -74,7 +76,7 @@ public class XtaClient {
 	}
 
 	void logWarnForNoMessageClosed() {
-		log.warn("No message has been closed although more are pending. Try increasing max list items.");
+		log.warn(NO_MESSAGE_CLOSED_WARNING);
 	}
 
 	List<XtaTransportReport> fetchMessagesForListing(

src/test/java/de/ozgcloud/xta/client/XtaClientITCase.java

 package de.ozgcloud.xta.client;
 
+import static de.ozgcloud.xta.client.XtaClient.*;
 import static de.ozgcloud.xta.client.extension.XtaServerSetupExtensionTestUtil.*;
 import static java.util.Collections.*;
 import static org.assertj.core.api.Assertions.*;
@@ -17,6 +18,7 @@ import org.junit.jupiter.api.Test;
 import org.junit.jupiter.api.extension.RegisterExtension;
 
 import de.ozgcloud.common.errorhandling.TechnicalException;
+import de.ozgcloud.xta.client.extension.StaticStringListAppender;
 import de.ozgcloud.xta.client.extension.XtaMessageExampleLoader;
 import de.ozgcloud.xta.client.extension.XtaTestServerSetupExtension;
 import de.ozgcloud.xta.client.model.XtaIdentifier;
@@ -50,6 +52,7 @@ class XtaClientITCase {
 		processedMessages = new ArrayList<>();
 		setupClient = XTA_TEST_SERVER_SETUP_EXTENSION.getSetupClient();
 
+		StaticStringListAppender.clearLogLines();
 		closeMessagesForAllReaders();
 	}
 
@@ -58,6 +61,7 @@ class XtaClientITCase {
 				.forEach(clientId -> closeAllMessages(setupClient, clientId));
 	}
 
+
 	@DisplayName("fetch messages")
 	@Nested
 	class TestFetchMessages {
@@ -190,6 +194,7 @@ class XtaClientITCase {
 			var transportReports = fetchMessages();
 
 			assertThat(supportCheckedMetadataItems).hasSize(1 + 3 + 2);
+			assertThat(hasLogLineContaining(NO_MESSAGE_CLOSED_WARNING)).isFalse();
 			assertThatMessages(processedMessages).containExactlyInAnyOrder(
 					sendMessages.get(0),
 					sendMessages.get(1), sendMessages.get(2), sendMessages.get(3),
@@ -211,38 +216,62 @@ class XtaClientITCase {
 
 			var transportReports = fetchMessages();
 
-			if (processedMessages.size() != 5) {
-				assertThat(supportCheckedMetadataItems).hasSize(1 + 3 + 2);
+			if (hasLogLineContaining(NO_MESSAGE_CLOSED_WARNING)) {
+				// The first listing for reader2 contained sendMessages.get(1) and sendMessages.get(2).
+				// Since no messages have been closed for this listing, no second listing for reader2 is attempted.
+				// Therefore, sendMessages.get(3) was not fetched.
+
+				assertThat(supportCheckedMetadataItems).hasSize(1 + 2 + 2);
 				assertThatMessages(processedMessages).containExactlyInAnyOrder(
 						sendMessages.get(0),
-						sendMessages.get(1), sendMessages.get(2), sendMessages.get(3),
+						sendMessages.get(1), sendMessages.get(2),
 						sendMessages.get(4), sendMessages.get(5)
 				);
 				assertThatTransportReports(transportReports)
 						.reportExactlyFor(processedMessages)
 						.haveExactlyGreenStatusFor(
-								messageIdBySendIndex(3),
 								messageIdBySendIndex(4)
 						);
 			} else {
-				// If (by chance) sendMessages.get(1), sendMessages.get(2) are fetched first, both are not closed due to the runtime exception.
-				// Which results in the warning: "No message has been closed although more are pending. Try increasing max list items."
-				// and sendMessages.get(3) not being fetched/checked or processed.
+				// The first listing for reader2 contained sendMessages.get(3).
 
-				assertThat(supportCheckedMetadataItems).hasSize(1 + 3 - 1 + 2);
+				assertThat(supportCheckedMetadataItems).hasSize(1 + 3 + 2);
 				assertThatMessages(processedMessages).containExactlyInAnyOrder(
 						sendMessages.get(0),
-						sendMessages.get(1), sendMessages.get(2),
+						sendMessages.get(1), sendMessages.get(2), sendMessages.get(3),
 						sendMessages.get(4), sendMessages.get(5)
 				);
 				assertThatTransportReports(transportReports)
 						.reportExactlyFor(processedMessages)
 						.haveExactlyGreenStatusFor(
+								messageIdBySendIndex(3),
 								messageIdBySendIndex(4)
 						);
 			}
 		}
 
+		@DisplayName("should close messages only if no exception occurs during processing, with no exception for author3")
+		@Test
+		void shouldCloseMessagesOnlyIfNoExceptionOccursDuringProcessingWithNoExceptionForAuthor3() {
+			setupClientWithIdentifiers(List.of(READER_CLIENT_IDENTIFIER1, READER_CLIENT_IDENTIFIER2, READER_CLIENT_IDENTIFIER3));
+			processMessageDummy = message -> throwRuntimeExceptionExceptForAuthorIdentifier(message, AUTHOR_CLIENT_IDENTIFIER3);
+
+			var transportReports = fetchMessages();
+
+			assertThat(supportCheckedMetadataItems).hasSize(1 + 2 + 2);
+			assertThat(hasLogLineContaining(NO_MESSAGE_CLOSED_WARNING)).isTrue();
+			assertThatMessages(processedMessages).containMetaDataExactlyInAnyOrder(
+					sendMessages.get(0).metaData(),
+					supportCheckedMetadataItems.get(1), supportCheckedMetadataItems.get(2),
+					sendMessages.get(4).metaData(), sendMessages.get(5).metaData()
+			);
+			assertThatTransportReports(transportReports)
+					.reportExactlyFor(processedMessages)
+					.haveExactlyGreenStatusFor(
+							messageIdBySendIndex(5)
+					);
+		}
+
 		private void throwRuntimeExceptionExceptForAuthorIdentifier(XtaMessage message, XtaIdentifier authorIdentifier) {
 			var authorId = message.metaData().authorIdentifier().value();
 			var readerId = message.metaData().readerIdentifier().value();
@@ -260,6 +289,7 @@ class XtaClientITCase {
 			var transportReports = fetchMessages();
 
 			assertThat(supportCheckedMetadataItems).hasSize(1 + 3 + 2);
+			assertThat(hasLogLineContaining(NO_MESSAGE_CLOSED_WARNING)).isFalse();
 			assertThatMessages(processedMessages).containExactlyInAnyOrder(sendMessages.get(0), sendMessages.get(1), sendMessages.get(2));
 			assertThatTransportReports(transportReports)
 					.reportExactlyFor(processedMessages)
@@ -274,13 +304,33 @@ class XtaClientITCase {
 
 			var transportReports = fetchMessages();
 
+			if (hasLogLineContaining(NO_MESSAGE_CLOSED_WARNING)) {
+				assertThat(supportCheckedMetadataItems).hasSize(1 + 2 + 2);
+			} else {
 				assertThat(supportCheckedMetadataItems).hasSize(1 + 3 + 2);
+			}
 			assertThatMessages(processedMessages).containExactlyInAnyOrder(sendMessages.get(3), sendMessages.get(4));
 			assertThatTransportReports(transportReports)
 					.reportExactlyFor(processedMessages)
 					.haveExactlyGreenStatusFor(messageIdBySendIndex(3), messageIdBySendIndex(4));
 		}
 
+		@DisplayName("should process messages only if supported, with support for author3")
+		@Test
+		void shouldProcessMessagesOnlyIfSupportedWithSupportForAuthor3() {
+			setupClientWithIdentifiers(List.of(READER_CLIENT_IDENTIFIER1, READER_CLIENT_IDENTIFIER2, READER_CLIENT_IDENTIFIER3));
+			isSupportedDummy = metaData -> metaData.authorIdentifier().value().equals(AUTHOR_CLIENT_IDENTIFIER3.value());
+
+			var transportReports = fetchMessages();
+
+			assertThat(supportCheckedMetadataItems).hasSize(1 + 2 + 2);
+			assertThat(hasLogLineContaining(NO_MESSAGE_CLOSED_WARNING)).isTrue();
+			assertThatMessages(processedMessages).containExactlyInAnyOrder(sendMessages.get(5));
+			assertThatTransportReports(transportReports)
+					.reportExactlyFor(processedMessages)
+					.haveExactlyGreenStatusFor(messageIdBySendIndex(5));
+		}
+
 		@SneakyThrows
 		private void setupClientWithIdentifiers(List<XtaIdentifier> identifiers) {
 			testClient = XtaClient.from(

src/test/java/de/ozgcloud/xta/client/extension/StaticStringListAppender.java

+package de.ozgcloud.xta.client.extension;
+
+import java.io.Serializable;
+import java.util.ArrayList;
+import java.util.List;
+import java.util.concurrent.ConcurrentLinkedQueue;
+
+import org.apache.logging.log4j.core.Filter;
+import org.apache.logging.log4j.core.Layout;
+import org.apache.logging.log4j.core.LogEvent;
+import org.apache.logging.log4j.core.appender.AbstractAppender;
+import org.apache.logging.log4j.core.config.Node;
+import org.apache.logging.log4j.core.config.Property;
+import org.apache.logging.log4j.core.config.plugins.Plugin;
+import org.apache.logging.log4j.core.config.plugins.PluginAttribute;
+import org.apache.logging.log4j.core.config.plugins.PluginFactory;
+
+@Plugin(name = "StaticStringList", category = Node.CATEGORY)
+public class StaticStringListAppender extends AbstractAppender {
+
+	private static final ConcurrentLinkedQueue<String> LOG_LINES = new ConcurrentLinkedQueue<>();
+
+	protected StaticStringListAppender(String name, Filter filter,
+			Layout<? extends Serializable> layout, boolean ignoreExceptions,
+			Property[] properties) {
+		super(name, filter, layout, ignoreExceptions, properties);
+	}
+
+	@PluginFactory
+	public static StaticStringListAppender createAppender(@PluginAttribute("name") String name) {
+		return new StaticStringListAppender(name, null, null, true, Property.EMPTY_ARRAY);
+	}
+
+	public static List<String> getLogLines() {
+		return new ArrayList<>(LOG_LINES);
+	}
+
+	public static void clearLogLines() {
+		LOG_LINES.clear();
+	}
+
+	@Override
+	public void append(LogEvent event) {
+		LOG_LINES.add(event.getMessage().getFormattedMessage());
+	}
+}

src/test/java/de/ozgcloud/xta/client/extension/XtaServerSetupExtensionTestUtil.java

@@ -134,17 +134,10 @@ public class XtaServerSetupExtensionTestUtil {
 	public record MessagesAssert(List<XtaMessage> processedMessages) {
 		public MessagesAssert containExactlyInAnyOrder(XtaMessage... messages) {
 			try {
-				// Assert equal message counts
-				assertThat(processedMessages).hasSize(messages.length);
-
-				// Assert equal metadata (ignoring message id and size since they should be null before sending)
-				assertThat(processedMessages)
-						.extracting(XtaMessage::metaData)
-						.extracting(XtaServerSetupExtensionTestUtil::withoutMessageIdAndSize)
-						.containsExactlyInAnyOrderElementsOf(Arrays.stream(messages)
+				containMetaDataExactlyInAnyOrder(Arrays.stream(messages)
 						.map(XtaMessage::metaData)
-								.map(XtaServerSetupExtensionTestUtil::withoutMessageIdAndSize)
-								.toList());
+						.toArray(XtaMessageMetaData[]::new)
+				);
 
 				// Assert equal message file and attachment files without content (ignoring size since it may be null before sending)
 				UnaryOperator<XtaFile> withoutContentAndSize = xtaFile -> xtaFile.toBuilder()
@@ -215,6 +208,24 @@ public class XtaServerSetupExtensionTestUtil {
 			}
 			return this;
 		}
+
+		public void containMetaDataExactlyInAnyOrder(XtaMessageMetaData... messageMetaDataItems) {
+			try {
+				// Assert equal message counts
+				assertThat(processedMessages).hasSize(messageMetaDataItems.length);
+
+				// Assert equal metadata (ignoring message id and size since they should be null before sending)
+				assertThat(processedMessages)
+						.extracting(XtaMessage::metaData)
+						.extracting(XtaServerSetupExtensionTestUtil::withoutMessageIdAndSize)
+						.containsExactlyInAnyOrderElementsOf(Arrays.stream(messageMetaDataItems)
+								.map(XtaServerSetupExtensionTestUtil::withoutMessageIdAndSize)
+								.toList());
+			} catch (AssertionError | RuntimeException e) {
+				log.error("Messages do not exactly contain excepted metadata!");
+				throw e;
+			}
+		}
 	}
 
 	public static MessagesAssert assertThatMessages(List<XtaMessage> processedMessages) {
@@ -267,6 +278,11 @@ public class XtaServerSetupExtensionTestUtil {
 		return new TransportReportsAssert(transportReports);
 	}
 
+	public static boolean hasLogLineContaining(String logLine) {
+		return StaticStringListAppender.getLogLines().stream()
+				.anyMatch(line -> line.contains(logLine));
+	}
+
 	private static List<byte[]> readBytesOfXtaFiles(List<XtaFile> xtaFiles) {
 		return xtaFiles.stream()
 				.map(XtaServerSetupExtensionTestUtil::readBytesOfXtaFile)

src/test/resources/log4j2.xml

 <?xml version="1.0" encoding="UTF-8"?>
-<Configuration name="log4j2Config" status="WARN">
+<Configuration name="log4j2Config" status="WARN" packages="de.ozgcloud.xta.client.extension">
 
     <Appenders>
         <Console name="Console" target="SYSTEM_OUT">
@@ -9,11 +9,13 @@
                     onMismatch="DENY" />
             </filters>
         </Console>
+        <StaticStringList name="StaticStringList" />
     </Appenders>
 
     <Loggers>
         <Logger name="de.ozgcloud.xta" level="debug" additivity="false">
             <AppenderRef ref="Console" level="${env:LOG_LEVEL_STDOUT:-debug}" />
+            <AppenderRef ref="StaticStringList" level="debug" />
         </Logger>
 
         <Root level="info">