Skip to content
Merged
Show file tree
Hide file tree
Changes from 7 commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
14 changes: 14 additions & 0 deletions .github/workflows/build.yml
Original file line number Diff line number Diff line change
Expand Up @@ -78,6 +78,20 @@ jobs:
name: ${{ matrix.type }} results
path: ${{ matrix.resultsdir }}

# Always upload any Hibernate teardown thread dumps captured by AbstractIntegrationTestWithDatabase
# when the rare ConcurrentModificationException race fires during @After cleanup. These are written
# even when the cleanup retry ultimately succeeds (so the build stays green), so this step must NOT be
# gated on failure() - otherwise a successful retry would hide the very diagnostic that pinpoints the
# colliding thread. 'if-no-files-found: ignore' keeps this a no-op on the (normal) runs with no CME.
- name: Upload Hibernate CME thread dumps (if any)
if: ${{ always() }}
uses: actions/upload-artifact@v4
with:
Comment thread
coderabbitai[bot] marked this conversation as resolved.
Outdated
name: ${{ matrix.type }} cme-dumps
path: '**/target/cme-dumps/**'
if-no-files-found: ignore
retention-days: 30

# Upload code coverage report to artifact, so that it can be shared with the 'codecov' job (see below)
- name: Upload code coverage report to Artifact
uses: actions/upload-artifact@v4
Expand Down
20 changes: 16 additions & 4 deletions dspace-api/src/main/java/org/dspace/core/AbstractHibernateDAO.java
Original file line number Diff line number Diff line change
Expand Up @@ -306,11 +306,23 @@ public Iterator<T> iterate(Query query) {
return new AbstractIterator<T> () {
@Override
protected T computeNext() {
return iter.hasNext() ? iter.next() : endOfData();
}
@Override
public void finalize() {
if (iter.hasNext()) {
return iter.next();
}
// Close the backing ScrollableResults / JDBC cursor as soon as the iteration is exhausted, on
// the thread that owns the Hibernate Session (the caller's thread).
//
// This MUST NOT be done from a finalize() override (as it previously was): finalize() runs on
// the GC Finalizer thread, so closing the stream there mutates the Session's per-session,
// non-thread-safe JDBC ResourceRegistry (xref) concurrently with the owning thread. That is a
// genuine data race which intermittently throws ConcurrentModificationException from
// ResourceRegistryStandardImpl.releaseResources during an unrelated commit/rollback (observed
// as flaky integration-test failures in AbstractIntegrationTestWithDatabase teardown).
//
// An iterator abandoned before exhaustion no longer leaks: its open statement is released
// safely when the owning Context/Session is closed (releaseResources runs on the owning thread).
stream.close();
return endOfData();
}
};
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -174,7 +174,9 @@ protected String getAccessToken(String clientSecret, String clientId, String OAU
}
}

private InputStream httpGet(String path, String accessToken) throws IOException {
// Package/sub-class visible so tests can stub the HTTP layer (see CachingOrcidRestConnectorTest)
// and avoid hitting the live ORCID sandbox.
protected InputStream httpGet(String path, String accessToken) throws IOException {
String trimmedPath = path.replaceFirst("^/+", "").replaceFirst("/+$", "");

String fullPath = apiURL + '/' + trimmedPath;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,12 @@

import static org.junit.Assert.fail;

import java.io.File;
import java.io.PrintWriter;
import java.sql.SQLException;
import java.util.ConcurrentModificationException;
import java.util.Map;
import java.util.concurrent.atomic.AtomicInteger;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
Expand Down Expand Up @@ -106,6 +111,12 @@ public static void initDatabase() {
@Before
public void setUp() throws Exception {
try {
// DIAGNOSTIC (temporary): start the JVM-wide Hibernate concurrency monitor and mark this JUnit
// thread as a legitimate test thread. The monitor hunts the transient thread behind the rare
// @After ConcurrentModificationException (see destroy()/dumpAllThreadsOnCme()).
HibernateConcurrencyMonitor.startOnce();
HibernateConcurrencyMonitor.markTestThread();

//Start a new context
context = new Context(Context.Mode.READ_WRITE);
context.turnOffAuthorisationSystem();
Expand Down Expand Up @@ -168,9 +179,50 @@ public void setUp() throws Exception {
public void destroy() throws Exception {
// Cleanup our global context object
try {
AbstractBuilder.cleanupObjects();
parentCommunity = null;
cleanupContext();
// Builders/cleanupContext commit transactions through Hibernate. We have observed a rare,
// CI-only intermittent ConcurrentModificationException thrown from
// ResourceRegistryStandardImpl#releaseResources (a HashMap.forEach over the JDBC resource
// registry) while committing here. That registry is per-Hibernate-Session and explicitly NOT
// thread-safe, so the CME means a second thread is touching the same Session concurrently
// during cleanup. The exact offending thread has not yet been identified (it does not
// reproduce locally), so on CME we (a) capture a full thread dump to pinpoint the colliding
// thread the next time it happens in CI, and (b) retry the cleanup so an already-passed test
// is not failed by this teardown race. See dumpAllThreadsOnCme().
final int maxCleanupAttempts = 3;
boolean cleanupComplete = false;
for (int cleanupAttempt = 1; cleanupAttempt <= maxCleanupAttempts; cleanupAttempt++) {
try {
AbstractBuilder.cleanupObjects();
parentCommunity = null;
cleanupContext();
cleanupComplete = true;
break;
} catch (ConcurrentModificationException cme) {
// Capture a full thread dump the instant the CME is caught, so we can see which OTHER
// thread is concurrently inside JDBC/Hibernate code on the same (non-thread-safe) session.
dumpAllThreadsOnCme(cme, cleanupAttempt);
// Also flush the background monitor's accumulated fingerprints of any non-test thread that
// was ever seen inside Hibernate JDBC/session code (the most reliable culprit signal).
HibernateConcurrencyMonitor.flush("cme-attempt" + cleanupAttempt);
log.warn("Transient Hibernate CME during @After cleanup (concurrent access to the "
+ "per-session JDBC resource registry), attempt {}/{}; aborting context, capturing a "
+ "thread dump and retrying cleanup.", cleanupAttempt, maxCleanupAttempts, cme);
if (context != null && context.isValid()) {
context.abort();
}
context = null;
parentCommunity = null;

if (cleanupAttempt < maxCleanupAttempts) {
context = new Context(Context.Mode.READ_WRITE);
context.turnOffAuthorisationSystem();
}
}
}

if (!cleanupComplete) {
throw new IllegalStateException("Unable to complete @After DB cleanup after retries.");
}

ServiceManager serviceManager = DSpaceServicesFactory.getInstance().getServiceManager();
// Clear the search core.
Expand Down Expand Up @@ -202,6 +254,47 @@ public void destroy() throws Exception {
}
}

// Counter to give each captured dump a unique file name.
private static final AtomicInteger CME_DUMP_COUNTER = new AtomicInteger(0);

/**
* Diagnostic helper: when a ConcurrentModificationException is caught during @After cleanup, dump the
* stack traces of ALL live threads to a file under target/cme-dumps/ (archived as a CI artifact). The
* CME is thrown on the test thread while another thread concurrently mutates the same Hibernate
* session's (non-thread-safe) JDBC ResourceRegistry; this dump is meant to reveal that other thread so
* the underlying concurrency bug can be fixed at its source.
*/
private static void dumpAllThreadsOnCme(ConcurrentModificationException cme, int attempt) {
try {
File dir = new File("target/cme-dumps");
dir.mkdirs();
int idx = CME_DUMP_COUNTER.incrementAndGet();
File out = new File(dir, "cme-" + System.currentTimeMillis() + "-" + idx + "-attempt" + attempt + ".txt");
try (PrintWriter pw = new PrintWriter(out, "UTF-8")) {
pw.println("===== ConcurrentModificationException caught during @After cleanup =====");
pw.println("Caught on thread: " + Thread.currentThread().getName());
pw.println("Attempt: " + attempt);
pw.println();
pw.println("----- CME stack -----");
cme.printStackTrace(pw);
pw.println();
pw.println("----- ALL THREAD STACKS at moment of CME -----");
for (Map.Entry<Thread, StackTraceElement[]> e : Thread.getAllStackTraces().entrySet()) {
Thread t = e.getKey();
pw.println();
pw.println("\"" + t.getName() + "\" id=" + t.getId() + " state=" + t.getState()
+ " daemon=" + t.isDaemon());
for (StackTraceElement ste : e.getValue()) {
pw.println("\tat " + ste);
}
}
}
log.error("CME thread dump written to {}", out.getAbsolutePath());
} catch (Exception dumpEx) {
log.error("Failed to write CME thread dump", dumpEx);
}
}

/**
* Utility method to cleanup a created Context object (to save memory).
* This can also be used by individual tests to cleanup context objects they create.
Expand Down
139 changes: 139 additions & 0 deletions dspace-api/src/test/java/org/dspace/HibernateConcurrencyMonitor.java
Original file line number Diff line number Diff line change
@@ -0,0 +1,139 @@
/**
* The contents of this file are subject to the license and copyright
* detailed in the LICENSE and NOTICE files at the root of the source
* tree and available online at
*
* http://www.dspace.org/license/
*/
package org.dspace;

import java.io.File;
import java.io.PrintWriter;
import java.util.Map;
import java.util.Set;
import java.util.concurrent.ConcurrentHashMap;

/**
* TEST DIAGNOSTIC (temporary) for the rare Hibernate {@code ConcurrentModificationException} thrown from
* {@code ResourceRegistryStandardImpl.releaseResources} during {@code @After} cleanup
* (see {@link AbstractIntegrationTestWithDatabase#destroy()}).
*
* <p>That CME provably requires a SECOND thread to mutate the test thread's per-session, non-thread-safe JDBC
* resource registry while the test thread commits/rolls back. A live thread-dump of a running IT JVM shows that
* NO legitimate background thread ever touches Hibernate (every persistent thread is Solr, HTTP-client, Jetty or
* a JVM thread). Therefore <b>any</b> non-test thread caught executing inside Hibernate JDBC / session code is,
* by definition, the culprit.</p>
*
* <p>This monitor is a JVM-wide background sampler. Every {@link #SAMPLE_INTERVAL_MS} ms it snapshots all thread
* stacks and records (de-duplicated) any non-test, non-monitor thread found inside
* {@code org.hibernate.resource.jdbc}, {@code org.hibernate.engine.jdbc} or {@code org.hibernate.internal.SessionImpl}.
* Records are flushed to {@code target/cme-dumps/} on a captured CME and at JVM shutdown. It is a pure observer:
* it never touches Hibernate, never throws into test code, and never changes behaviour. Delete once the culprit
* thread has been identified and fixed at its source.</p>
*/
public final class HibernateConcurrencyMonitor {

private static final long SAMPLE_INTERVAL_MS = 20;

/** Thread ids of legitimate test threads (the JUnit thread(s)) to ignore. */
private static final Set<Long> TEST_THREAD_IDS = ConcurrentHashMap.newKeySet();

/** De-duplicated culprit fingerprints: key -> formatted record. */
private static final Map<String, String> CULPRITS = new ConcurrentHashMap<>();

private static volatile boolean started;

private HibernateConcurrencyMonitor() {
}

/** Start the monitor exactly once per JVM (fork). Safe to call from every test's setUp. */
public static synchronized void startOnce() {
if (started) {
return;
}
started = true;
Thread t = new Thread(HibernateConcurrencyMonitor::loop, "hibernate-concurrency-monitor");
t.setDaemon(true);
t.start();
Runtime.getRuntime().addShutdownHook(new Thread(() -> flush("jvm-shutdown"), "hibernate-concurrency-flush"));
}

/** Mark the current thread as a legitimate test thread, so its (normal) Hibernate use is ignored. */
public static void markTestThread() {
TEST_THREAD_IDS.add(Thread.currentThread().getId());
}

private static void loop() {
final long monitorId = Thread.currentThread().getId();
while (true) {
try {
Map<Thread, StackTraceElement[]> all = Thread.getAllStackTraces();
for (Map.Entry<Thread, StackTraceElement[]> e : all.entrySet()) {
Thread th = e.getKey();
if (th.getId() == monitorId || TEST_THREAD_IDS.contains(th.getId())) {
continue;
}
if (touchesHibernateJdbc(e.getValue())) {
record(th, e.getValue());
}
}
Thread.sleep(SAMPLE_INTERVAL_MS);
} catch (InterruptedException ie) {
return;
} catch (Throwable ignore) {
// A diagnostic must never die from a transient error (e.g. a thread terminating mid-snapshot).
}
}
}

private static boolean touchesHibernateJdbc(StackTraceElement[] stack) {
for (StackTraceElement f : stack) {
String c = f.getClassName();
if (c.startsWith("org.hibernate.resource.jdbc")
|| c.startsWith("org.hibernate.engine.jdbc")
|| c.startsWith("org.hibernate.internal.SessionImpl")) {
return true;
}
}
return false;
}

private static void record(Thread th, StackTraceElement[] stack) {
StringBuilder sb = new StringBuilder();
int n = Math.min(stack.length, 25);
for (int i = 0; i < n; i++) {
sb.append("\tat ").append(stack[i]).append('\n');
}
String stackText = sb.toString();
String key = th.getName() + "|" + Integer.toHexString(stackText.hashCode());
CULPRITS.putIfAbsent(key, "\"" + th.getName() + "\" id=" + th.getId()
+ " daemon=" + th.isDaemon() + " state=" + th.getState()
+ " group=" + (th.getThreadGroup() == null ? "?" : th.getThreadGroup().getName()) + "\n" + stackText);
}

/** Write all captured culprit fingerprints to target/cme-dumps/ (no-op if none were caught). */
public static void flush(String reason) {
if (CULPRITS.isEmpty()) {
return;
}
try {
File dir = new File("target/cme-dumps");
dir.mkdirs();
File out = new File(dir, "hibernate-concurrency-" + System.currentTimeMillis() + "-" + reason + ".txt");
try (PrintWriter pw = new PrintWriter(out, "UTF-8")) {
pw.println("===== Non-test threads caught INSIDE Hibernate JDBC / session code =====");
pw.println("reason=" + reason + " distinctFingerprints=" + CULPRITS.size());
pw.println("Baseline: NO legitimate background thread touches Hibernate, so each entry below is a");
pw.println("suspect for the @After ConcurrentModificationException (concurrent access to the test");
pw.println("thread's non-thread-safe per-session JDBC ResourceRegistry).");
pw.println();
for (String rec : CULPRITS.values()) {
pw.println(rec);
pw.println("------------------------------------------------------------");
}
}
} catch (Exception ignore) {
// best-effort diagnostic
}
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,64 @@
/**
* The contents of this file are subject to the license and copyright
* detailed in the LICENSE and NOTICE files at the root of the source
* tree and available online at
*
* http://www.dspace.org/license/
*/
package org.dspace.core;

import static org.junit.Assert.assertNotNull;
import static org.junit.Assert.fail;

import java.util.Iterator;

import org.dspace.AbstractIntegrationTestWithDatabase;
import org.dspace.content.MetadataValue;
import org.dspace.content.factory.ContentServiceFactory;
import org.dspace.content.service.MetadataValueService;
import org.junit.Test;

/**
* Regression test for the intermittent {@code ConcurrentModificationException} thrown during
* {@code @After} integration-test cleanup and traced to
* {@link AbstractHibernateDAO#iterate(javax.persistence.Query)}.
*
* <p>That method used to close its Hibernate {@code Stream} from a {@code finalize()} override. {@code finalize()}
* runs on the GC Finalizer thread, so closing the stream there mutated the owning {@code Session}'s per-session,
* non-thread-safe JDBC {@code ResourceRegistry} (xref) concurrently with the thread that owns the session. That
* is a genuine data race which intermittently threw {@code ConcurrentModificationException} from
* {@code ResourceRegistryStandardImpl.releaseResources} during an unrelated commit/rollback. The fix closes the
* stream on the owning thread once the iteration is exhausted. This test guards against reintroducing any
* stream-closing finalizer on the returned iterator.</p>
*/
public class AbstractHibernateDAOIteratorIT extends AbstractIntegrationTestWithDatabase {

private final MetadataValueService metadataValueService =
ContentServiceFactory.getInstance().getMetadataValueService();

@Test
public void iterateIteratorMustNotCloseStreamFromFinalizer() throws Exception {
Comment thread
coderabbitai[bot] marked this conversation as resolved.
// findByValueLike() delegates to AbstractHibernateDAO.iterate(); the concrete (anonymous) iterator type
// is what we assert on. No matching rows are required - the wrapper iterator is created regardless.
Iterator<MetadataValue> iterator =
metadataValueService.findByValueLike(context, "no-such-metadata-value-" + System.nanoTime());
assertNotNull(iterator);

// The returned iterator MUST NOT declare its own finalize(): closing the backing Hibernate Stream from
// the GC Finalizer thread is exactly the cross-thread access to the non-thread-safe JDBC
// ResourceRegistry that caused the flaky ConcurrentModificationException.
try {
iterator.getClass().getDeclaredMethod("finalize");
fail("AbstractHibernateDAO.iterate() iterator must not declare a finalize() override - closing the "
+ "Hibernate Stream on the GC Finalizer thread races the owning thread's non-thread-safe "
+ "JDBC ResourceRegistry and intermittently throws ConcurrentModificationException.");
} catch (NoSuchMethodException expected) {
Comment thread
coderabbitai[bot] marked this conversation as resolved.
Outdated
// good: no stream-closing finalizer on the iterator
}

// It must still iterate to exhaustion and close its cursor on THIS (the owning) thread without error.
while (iterator.hasNext()) {
assertNotNull(iterator.next());
}
}
}
Loading
Loading