This is an automated email from the ASF dual-hosted git repository.
desruisseaux pushed a commit to branch geoapi-4.0
in repository https://gitbox.apache.org/repos/asf/sis.git
commit 9c5d68f70b565659e86fa67344bf510eb81522a6
Author: Martin Desruisseaux <martin.desruisse...@geomatys.com>
AuthorDate: Tue Feb 20 10:36:06 2024 +0100
Logs handled by the wrong `LoggingWatcher` during execution of tests in
parallel.
Require Java 16 for the test (but not for the main code, which still on
Java 11)
for avoiding an unreliable hack in `JDK16` placeholder class.
---
endorsed/build.gradle.kts | 2 ++
.../factory/ConcurrentAuthorityFactoryTest.java | 38 +++++++++++++-------
.../main/org/apache/sis/pending/jdk/JDK16.java | 29 ----------------
.../test/org/apache/sis/test/LoggingWatcher.java | 40 ++++++++++------------
4 files changed, 46 insertions(+), 63 deletions(-)
diff --git a/endorsed/build.gradle.kts b/endorsed/build.gradle.kts
index d3198451b9..6a8f136011 100644
--- a/endorsed/build.gradle.kts
+++ b/endorsed/build.gradle.kts
@@ -104,6 +104,8 @@ tasks.compileTestJava {
srcDir.list().forEach {
addRead(options.compilerArgs, it,
"org.apache.sis.test.endorsed,org.junit.jupiter.api")
}
+ options.compilerArgs.add("-source") // "source", not "release",
because we accept any target version.
+ options.compilerArgs.add("16") // Minimal Java version
required by some API that the tests use.
addExportForTests(options.compilerArgs)
}
diff --git
a/endorsed/src/org.apache.sis.referencing/test/org/apache/sis/referencing/factory/ConcurrentAuthorityFactoryTest.java
b/endorsed/src/org.apache.sis.referencing/test/org/apache/sis/referencing/factory/ConcurrentAuthorityFactoryTest.java
index 884c82c107..b1c7e84cf1 100644
---
a/endorsed/src/org.apache.sis.referencing/test/org/apache/sis/referencing/factory/ConcurrentAuthorityFactoryTest.java
+++
b/endorsed/src/org.apache.sis.referencing/test/org/apache/sis/referencing/factory/ConcurrentAuthorityFactoryTest.java
@@ -21,6 +21,7 @@ import java.util.ArrayList;
import java.util.Queue;
import java.util.concurrent.ConcurrentLinkedQueue;
import java.util.concurrent.TimeUnit;
+import java.util.function.Supplier;
import java.lang.reflect.Field;
import org.opengis.util.FactoryException;
import static
org.apache.sis.util.internal.StandardDateFormat.NANOS_PER_MILLISECOND;
@@ -118,10 +119,11 @@ public final class ConcurrentAuthorityFactoryTest extends
TestCase {
assertEquals(1, factory.countAvailableDataAccess(), "Expected one
valid DAO.");
assertFalse (createdDAOs.get(0).isClosed(), "Should not be
disposed yet.");
- sleepUntilAfterTimeout(3 *
ConcurrentAuthorityFactory.TIMEOUT_RESOLUTION, factory);
- assertEquals(createdDAOs, factory.createdDAOs(), "Expected no new
DAO.");
- assertEquals(0, factory.countAvailableDataAccess(), "Worker should be
disposed.");
- assertTrue (createdDAOs.get(0).isClosed(), "Worker should be
disposed.");
+ boolean expired;
+ expired = sleepUntilAfterTimeout(3 *
ConcurrentAuthorityFactory.TIMEOUT_RESOLUTION, factory);
+ assertEquals(createdDAOs, factory.createdDAOs(),
unexpectedDAO("Expected no new DAO.", expired));
+ assertEquals(0, factory.countAvailableDataAccess(),
unexpectedDAO("Worker should be disposed.", expired));
+ assertTrue (createdDAOs.get(0).isClosed(),
unexpectedDAO("Worker should be disposed.", expired));
/*
* Ask again for the same object and check that no new DAO
* were created because the value was taken from the cache.
@@ -156,11 +158,11 @@ public final class ConcurrentAuthorityFactoryTest extends
TestCase {
assertFalse (createdDAOs.get(1).isClosed(), "Should not be
disposed yet.");
assertEquals(createdDAOs, factory.createdDAOs(), "Expected no new
DAO.");
- sleepUntilAfterTimeout(3 *
ConcurrentAuthorityFactory.TIMEOUT_RESOLUTION, factory);
- assertEquals(createdDAOs, factory.createdDAOs(), "Expected no new
DAO.");
- assertEquals(0, factory.countAvailableDataAccess(), "Worker should be
disposed.");
- assertTrue (createdDAOs.get(1).isClosed(), "Worker should be
disposed.");
- assertTrue (createdDAOs.get(0).isClosed(), "Worker should be
disposed.");
+ expired = sleepUntilAfterTimeout(3 *
ConcurrentAuthorityFactory.TIMEOUT_RESOLUTION, factory);
+ assertEquals(createdDAOs, factory.createdDAOs(),
unexpectedDAO("Expected no new DAO.", expired));
+ assertEquals(0, factory.countAvailableDataAccess(),
unexpectedDAO("Worker should be disposed.", expired));
+ assertTrue (createdDAOs.get(1).isClosed(),
unexpectedDAO("Worker should be disposed.", expired));
+ assertTrue (createdDAOs.get(0).isClosed(),
unexpectedDAO("Worker should be disposed.", expired));
}
/**
@@ -182,19 +184,31 @@ public final class ConcurrentAuthorityFactoryTest extends
TestCase {
* it is subject to the hazard of thread scheduling.</p>
*
* @param waitTime the time to wait, in nanoseconds.
+ * @return whether there is more pending factories to dispose.
*/
- private static void sleepUntilAfterTimeout(final long waitTime, final
ConcurrentAuthorityFactory<?> factory)
+ private static boolean sleepUntilAfterTimeout(final long waitTime, final
ConcurrentAuthorityFactory<?> factory)
throws InterruptedException
{
Thread.sleep(TimeUnit.NANOSECONDS.toMillis(waitTime));
int n = 3;
while (factory.isCleanScheduled()) {
- ConcurrentAuthorityFactory.LOGGER.warning("Execution of
ConcurrentAuthorityFactory.disposeExpired() has been delayed.");
Thread.sleep(TIMEOUT / NANOS_PER_MILLISECOND);
System.gc();
if (--n == 0) {
- break;
+ return true;
}
}
+ return false;
+ }
+
+ /**
+ * Returns the supplier of the error message to report if a
timeout-dependent test fails.
+ *
+ * @param message the message.
+ * @param expired the result of the call to {@link
#sleepUntilAfterTimeout(long, ConcurrentAuthorityFactory)}.
+ * @return the supplied to give to a JUnit {@code assert} method.
+ */
+ private static Supplier<String> unexpectedDAO(final String message, final
boolean expired) {
+ return () -> expired ? message + " Note: the execution of
ConcurrentAuthorityFactory.disposeExpired() has been delayed." : message;
}
}
diff --git
a/endorsed/src/org.apache.sis.util/main/org/apache/sis/pending/jdk/JDK16.java
b/endorsed/src/org.apache.sis.util/main/org/apache/sis/pending/jdk/JDK16.java
index a756e706c7..53270b08ea 100644
---
a/endorsed/src/org.apache.sis.util/main/org/apache/sis/pending/jdk/JDK16.java
+++
b/endorsed/src/org.apache.sis.util/main/org/apache/sis/pending/jdk/JDK16.java
@@ -18,7 +18,6 @@ package org.apache.sis.pending.jdk;
import java.util.List;
import java.util.stream.Stream;
-import java.util.logging.LogRecord;
import org.apache.sis.util.internal.UnmodifiableArrayList;
@@ -45,32 +44,4 @@ public final class JDK16 {
public static <T> List<T> toList(final Stream<T> s) {
return (List<T>) UnmodifiableArrayList.wrap(s.toArray());
}
-
- /**
- * Place holder for {@code LogRecord.getLongThreadID()}.
- *
- * @param record the record for which to get the thread identifier.
- * @return thread identifier of the given record.
- */
- @SuppressWarnings("deprecation")
- public static long getLongThreadID(final LogRecord record) {
- return record.getThreadID();
- }
-
- /**
- * Returns {@code true} if the thread identifier of the given record is
probably equal to the given identifier.
- * This method reproduces the hashing algorithm used in {@code
LogRecord.shortThreadID(long)} private method.
- *
- * @param record the record for which to compare the thread identifier.
- * @param threadId the thread identifier to compare.
- * @return whether the thread identifier of the given record is probably
equal to the given value.
- */
- @SuppressWarnings("deprecation")
- public static boolean isSameThread(final LogRecord record, final long
threadId) {
- int hash = Long.hashCode(threadId);
- if (threadId < 0 || threadId > Integer.MAX_VALUE) {
- if (hash >= 0) hash = ~hash; // Makes it negative.
- }
- return record.getThreadID() == hash;
- }
}
diff --git
a/endorsed/src/org.apache.sis.util/test/org/apache/sis/test/LoggingWatcher.java
b/endorsed/src/org.apache.sis.util/test/org/apache/sis/test/LoggingWatcher.java
index 5c3697cf6e..f4047385b7 100644
---
a/endorsed/src/org.apache.sis.util/test/org/apache/sis/test/LoggingWatcher.java
+++
b/endorsed/src/org.apache.sis.util/test/org/apache/sis/test/LoggingWatcher.java
@@ -25,7 +25,6 @@ import java.util.logging.Level;
import java.util.logging.Logger;
import java.util.logging.LogRecord;
import java.util.logging.SimpleFormatter;
-import org.apache.sis.pending.jdk.JDK16;
// Test dependencies
import static org.junit.jupiter.api.Assertions.*;
@@ -129,7 +128,7 @@ public final class LoggingWatcher implements
BeforeEachCallback, AfterEachCallba
* All filters registered on the logger. This is a singleton containing
only {@code this},
* unless many tests are running in parallel with their own {@code
LoggingWatcher}.
*/
- private Queue<Filter> allFilters;
+ private Queue<LoggingWatcher> allFilters;
/**
* Creates a new watcher for the given logger.
@@ -183,14 +182,13 @@ public final class LoggingWatcher implements
BeforeEachCallback, AfterEachCallba
synchronized (logger) {
assertNull(allFilters);
final Filter current = logger.getFilter();
- if (current instanceof LoggingWatcher) {
- allFilters = ((LoggingWatcher) current).allFilters;
+ if (current != null) {
+ var w = assertInstanceOf(LoggingWatcher.class, current, () ->
"The \"" + logger.getName()
+ + "\" logger has a " +
current.getClass().getCanonicalName() + " filter.");
+ allFilters = w.allFilters;
assertNotNull(allFilters);
} else {
allFilters = new LinkedList<>();
- if (current != null) {
- allFilters.add(current);
- }
logger.setFilter(this);
}
allFilters.add(this);
@@ -221,26 +219,24 @@ public final class LoggingWatcher implements
BeforeEachCallback, AfterEachCallba
*/
@Override
public final boolean isLoggable(final LogRecord record) {
- /*
- * In the simple mono-thread case, everything use fields of `this`.
- * However, if many tests are running in parallel, we need to check
- * which `LoggingWatcher` should take the given log record.
- */
- LoggingWatcher owner = this;
- synchronized (logger) {
- for (final Filter filter : allFilters) {
- if (filter instanceof LoggingWatcher) {
- final var w = (LoggingWatcher) filter;
- if (w.isMultiThread || JDK16.isSameThread(record,
w.threadId)) {
+ if (record.getLevel().intValue() >= Level.INFO.intValue()) {
+ /*
+ * In the simple mono-thread case, everything use fields of `this`.
+ * However, if many tests are running in parallel, we need to check
+ * which `LoggingWatcher` should take the given log record.
+ */
+ LoggingWatcher owner = null;
+ synchronized (logger) {
+ for (final LoggingWatcher w : allFilters) {
+ if (w.isMultiThread || w.threadId ==
record.getLongThreadID()) {
owner = w;
break;
}
- } else if (!filter.isLoggable(record)) {
- return false;
}
}
- }
- if (record.getLevel().intValue() >= Level.INFO.intValue()) {
+ if (owner == null) {
+ return true;
+ }
synchronized (owner) {
owner.messages.add(owner.formatter.formatMessage(record));
}
