From ea3c8bca2e3a084f251f462ef308b1eaca42f1fa Mon Sep 17 00:00:00 2001 From: Adam Retter Date: Wed, 2 Oct 2024 19:00:17 +0200 Subject: [PATCH 1/8] [ci] Switch from Temurin to Liberica as it still supports macOS JDK 8 --- .github/workflows/ci.yml | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index c0c509f003e..bc793293872 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -12,9 +12,9 @@ jobs: steps: - uses: actions/checkout@v2 - name: Set up JDK ${{ matrix.jdk }} - uses: actions/setup-java@v2 + uses: actions/setup-java@v4 with: - distribution: temurin + distribution: liberica java-version: ${{ matrix.jdk }} - name: Cache local Ivy repository uses: actions/cache@v2 From 914bfec7c5356286a5d86593c0e86415840c0995 Mon Sep 17 00:00:00 2001 From: Adam Retter Date: Wed, 2 Oct 2024 19:05:08 +0200 Subject: [PATCH 2/8] [ci] Update GitHub actions plugin versions --- .github/workflows/ci.yml | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index bc793293872..82779c42434 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -10,14 +10,14 @@ jobs: jdk: ['8'] runs-on: ${{ matrix.os }} steps: - - uses: actions/checkout@v2 + - uses: actions/checkout@v4 - name: Set up JDK ${{ matrix.jdk }} uses: actions/setup-java@v4 with: distribution: liberica java-version: ${{ matrix.jdk }} - name: Cache local Ivy repository - uses: actions/cache@v2 + uses: actions/cache@v4 with: path: ~/.ivy/cache key: ${{ runner.os }}-ivy-${{ hashFiles('**/ivy.xml') }} @@ -39,7 +39,7 @@ jobs: run: ./build.sh test -Dtest.haltonerror=true -Dtest.haltonfailure=true - name: Archive build logs if: always() - uses: actions/upload-artifact@v2 + uses: actions/upload-artifact@v4 with: name: ${{ runner.os }}-jdk${{ matrix.jdk }}-build-logs retention-days: 5 From ccff6f9f8b17f78640d584f7e740e72140b2af7c Mon Sep 17 00:00:00 2001 From: Adam Retter Date: Wed, 2 Oct 2024 21:26:48 +0200 Subject: [PATCH 3/8] [bugfix] Make sure Journal Recovery progress bars reach 100% --- .../storage/recovery/RecoveryManager.java | 19 +++++++++++++------ 1 file changed, 13 insertions(+), 6 deletions(-) diff --git a/exist-core/src/main/java/org/exist/storage/recovery/RecoveryManager.java b/exist-core/src/main/java/org/exist/storage/recovery/RecoveryManager.java index b7d78f9f538..fc2da41fdef 100644 --- a/exist-core/src/main/java/org/exist/storage/recovery/RecoveryManager.java +++ b/exist-core/src/main/java/org/exist/storage/recovery/RecoveryManager.java @@ -121,10 +121,10 @@ public boolean recover() throws LogException { Lsn lastLsn = Lsn.LSN_INVALID; Loggable next; try { - final ProgressBar progress = new ProgressBar("Scanning journal ", FileUtils.sizeQuietly(last)); + final long lastSize = FileUtils.sizeQuietly(last); + final ProgressBar scanProgressBar = new ProgressBar("Scanning journal ", lastSize); while ((next = reader.nextEntry()) != null) { // LOG.debug(next.dump()); - progress.set(next.getLsn().getOffset()); if (next.getLogType() == LogEntryTypes.TXN_START) { // new transaction starts: add it to the transactions table txnsStarted.put(next.getTransactionId(), next); @@ -136,7 +136,10 @@ public boolean recover() throws LogException { lastCheckpoint = (Checkpoint) next; } lastLsn = next.getLsn(); + + scanProgressBar.set(next.getLsn().getOffset()); } + scanProgressBar.set(lastSize); // 100% } catch (final LogException e) { if (LOG.isDebugEnabled()) { LOG.debug("Caught exception while reading log", e); @@ -251,10 +254,11 @@ private void doRecovery(final int txnCount, final Path last, final JournalReader // ------- REDO --------- if (LOG.isInfoEnabled()) {LOG.info("First pass: redoing " + txnCount + " transactions...");} - final ProgressBar progress = new ProgressBar("Redo ", FileUtils.sizeQuietly(last)); Loggable next = null; int redoCnt = 0; try { + final long lastSize = FileUtils.sizeQuietly(last); + final ProgressBar redoProgressBar = new ProgressBar("Redo ", lastSize); while ((next = reader.nextEntry()) != null) { SanityCheck.ASSERT(next.getLogType() != LogEntryTypes.CHECKPOINT, "Found a checkpoint during recovery run! This should not ever happen."); @@ -272,10 +276,13 @@ private void doRecovery(final int txnCount, final Path last, final JournalReader // LOG.debug("Redo: " + next.dump()); // redo the log entry next.redo(); - progress.set(next.getLsn().getOffset()); - if (next.getLsn().equals(lastLsn)) - {break;} // last readable entry reached. Stop here. + redoProgressBar.set(next.getLsn().getOffset()); + if (next.getLsn().equals(lastLsn)) { + // last readable entry reached. Stop here. + break; + } } + redoProgressBar.set(lastSize); // 100% done } catch (final Exception e) { LOG.error("Exception caught while redoing transactions. Aborting recovery to avoid possible damage. " + "Before starting again, make sure to run a check via the emergency export tool.", e); From 0086de2914f2f62d6ba6d56aba332b5c1b7e7fd2 Mon Sep 17 00:00:00 2001 From: Adam Retter Date: Wed, 2 Oct 2024 21:28:03 +0200 Subject: [PATCH 4/8] [bugfix] Add missing Undo progress bar for Journal Recovery --- .../java/org/exist/storage/recovery/RecoveryManager.java | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/exist-core/src/main/java/org/exist/storage/recovery/RecoveryManager.java b/exist-core/src/main/java/org/exist/storage/recovery/RecoveryManager.java index fc2da41fdef..b7c8e6873a2 100644 --- a/exist-core/src/main/java/org/exist/storage/recovery/RecoveryManager.java +++ b/exist-core/src/main/java/org/exist/storage/recovery/RecoveryManager.java @@ -301,6 +301,8 @@ private void doRecovery(final int txnCount, final Path last, final JournalReader if (runningTxns.size() > 0) { // do a reverse scan of the log, undoing all uncommitted transactions try { + final long lastSize = FileUtils.sizeQuietly(last); + final ProgressBar undoProgressBar = new ProgressBar("Undo ", lastSize); while((next = reader.previousEntry()) != null) { if (next.getLogType() == LogEntryTypes.TXN_START) { if (runningTxns.get(next.getTransactionId()) != null) { @@ -321,7 +323,10 @@ private void doRecovery(final int txnCount, final Path last, final JournalReader // LOG.debug("Undo: " + next.dump()); next.undo(); } + + undoProgressBar.set(lastSize - next.getLsn().getOffset()); } + undoProgressBar.set(lastSize); // 100% done } catch (final Exception e) { LOG.warn("Exception caught while undoing dirty transactions. Remaining transactions " + "to be undone: " + runningTxns.size() + ". Aborting recovery to avoid possible damage. " + From 4355533a3217cb97cd8de23a95c2ccc293996d8f Mon Sep 17 00:00:00 2001 From: Adam Retter Date: Wed, 2 Oct 2024 21:29:37 +0200 Subject: [PATCH 5/8] [ignore] Small code cleanup --- .../java/org/exist/storage/recovery/RecoveryManager.java | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/exist-core/src/main/java/org/exist/storage/recovery/RecoveryManager.java b/exist-core/src/main/java/org/exist/storage/recovery/RecoveryManager.java index b7c8e6873a2..1b66e746a25 100644 --- a/exist-core/src/main/java/org/exist/storage/recovery/RecoveryManager.java +++ b/exist-core/src/main/java/org/exist/storage/recovery/RecoveryManager.java @@ -150,7 +150,7 @@ public boolean recover() throws LogException { // if the last checkpoint record is not the last record in the file // we need a recovery. if ((lastCheckpoint == null || !lastCheckpoint.getLsn().equals(lastLsn)) && - txnsStarted.size() > 0) { + !txnsStarted.isEmpty()) { LOG.info("Dirty transactions: " + txnsStarted.size()); // starting recovery: reposition the log reader to the last checkpoint if (lastCheckpoint == null) @@ -298,7 +298,7 @@ private void doRecovery(final int txnCount, final Path last, final JournalReader {LOG.info("Second pass: undoing dirty transactions. Uncommitted transactions: " + runningTxns.size());} // see if there are uncommitted transactions pending - if (runningTxns.size() > 0) { + if (!runningTxns.isEmpty()) { // do a reverse scan of the log, undoing all uncommitted transactions try { final long lastSize = FileUtils.sizeQuietly(last); @@ -307,9 +307,10 @@ private void doRecovery(final int txnCount, final Path last, final JournalReader if (next.getLogType() == LogEntryTypes.TXN_START) { if (runningTxns.get(next.getTransactionId()) != null) { runningTxns.remove(next.getTransactionId()); - if (runningTxns.size() == 0) + if (runningTxns.isEmpty()) { // all dirty transactions undone - {break;} + break; + } } } else if (next.getLogType() == LogEntryTypes.TXN_COMMIT) { // ignore already committed transaction From e2101da422c4a1f2c87456d465220fca2fc7ea30 Mon Sep 17 00:00:00 2001 From: Adam Retter Date: Wed, 2 Oct 2024 21:34:52 +0200 Subject: [PATCH 6/8] [feature] Add the System Property 'exist.recovery.progressbar.hide' to hide the Journal Recovery progress bars --- .../storage/recovery/RecoveryManager.java | 39 ++++++++++++++----- 1 file changed, 30 insertions(+), 9 deletions(-) diff --git a/exist-core/src/main/java/org/exist/storage/recovery/RecoveryManager.java b/exist-core/src/main/java/org/exist/storage/recovery/RecoveryManager.java index 1b66e746a25..7798a537a16 100644 --- a/exist-core/src/main/java/org/exist/storage/recovery/RecoveryManager.java +++ b/exist-core/src/main/java/org/exist/storage/recovery/RecoveryManager.java @@ -45,6 +45,8 @@ import com.evolvedbinary.j8fu.function.SupplierE; import org.exist.util.sanity.SanityCheck; +import javax.annotation.Nullable; + /** * Database recovery. This class is used once during startup to check * if the database is in a consistent state. If not, the class attempts to recover @@ -59,11 +61,13 @@ public class RecoveryManager { private final DBBroker broker; private final JournalRecoveryAccessor journalRecovery; private final boolean restartOnError; + private final boolean hideProgressBar; public RecoveryManager(final DBBroker broker, final JournalManager journalManager, final boolean restartOnError) { this.broker = broker; this.journalRecovery = journalManager.getRecoveryAccessor(this); this.restartOnError = restartOnError; + this.hideProgressBar = Boolean.getBoolean("exist.recovery.progressbar.hide"); } /** @@ -122,7 +126,7 @@ public boolean recover() throws LogException { Loggable next; try { final long lastSize = FileUtils.sizeQuietly(last); - final ProgressBar scanProgressBar = new ProgressBar("Scanning journal ", lastSize); + @Nullable final ProgressBar scanProgressBar = hideProgressBar ? null : new ProgressBar("Scanning journal ", lastSize); while ((next = reader.nextEntry()) != null) { // LOG.debug(next.dump()); if (next.getLogType() == LogEntryTypes.TXN_START) { @@ -137,9 +141,14 @@ public boolean recover() throws LogException { } lastLsn = next.getLsn(); - scanProgressBar.set(next.getLsn().getOffset()); + if (scanProgressBar != null) { + scanProgressBar.set(next.getLsn().getOffset()); + } } - scanProgressBar.set(lastSize); // 100% + + if (scanProgressBar != null) { + scanProgressBar.set(lastSize); // 100% + } } catch (final LogException e) { if (LOG.isDebugEnabled()) { LOG.debug("Caught exception while reading log", e); @@ -258,7 +267,7 @@ private void doRecovery(final int txnCount, final Path last, final JournalReader int redoCnt = 0; try { final long lastSize = FileUtils.sizeQuietly(last); - final ProgressBar redoProgressBar = new ProgressBar("Redo ", lastSize); + @Nullable final ProgressBar redoProgressBar = hideProgressBar ? null : new ProgressBar("Redo ", lastSize); while ((next = reader.nextEntry()) != null) { SanityCheck.ASSERT(next.getLogType() != LogEntryTypes.CHECKPOINT, "Found a checkpoint during recovery run! This should not ever happen."); @@ -276,13 +285,20 @@ private void doRecovery(final int txnCount, final Path last, final JournalReader // LOG.debug("Redo: " + next.dump()); // redo the log entry next.redo(); - redoProgressBar.set(next.getLsn().getOffset()); + + if (redoProgressBar != null) { + redoProgressBar.set(next.getLsn().getOffset()); + } + if (next.getLsn().equals(lastLsn)) { // last readable entry reached. Stop here. break; } } - redoProgressBar.set(lastSize); // 100% done + + if (redoProgressBar != null) { + redoProgressBar.set(lastSize); // 100% done + } } catch (final Exception e) { LOG.error("Exception caught while redoing transactions. Aborting recovery to avoid possible damage. " + "Before starting again, make sure to run a check via the emergency export tool.", e); @@ -302,7 +318,7 @@ private void doRecovery(final int txnCount, final Path last, final JournalReader // do a reverse scan of the log, undoing all uncommitted transactions try { final long lastSize = FileUtils.sizeQuietly(last); - final ProgressBar undoProgressBar = new ProgressBar("Undo ", lastSize); + @Nullable final ProgressBar undoProgressBar = hideProgressBar ? null : new ProgressBar("Undo ", lastSize); while((next = reader.previousEntry()) != null) { if (next.getLogType() == LogEntryTypes.TXN_START) { if (runningTxns.get(next.getTransactionId()) != null) { @@ -325,9 +341,14 @@ private void doRecovery(final int txnCount, final Path last, final JournalReader next.undo(); } - undoProgressBar.set(lastSize - next.getLsn().getOffset()); + if (undoProgressBar != null) { + undoProgressBar.set(lastSize - next.getLsn().getOffset()); + } + } + + if (undoProgressBar != null) { + undoProgressBar.set(lastSize); // 100% done } - undoProgressBar.set(lastSize); // 100% done } catch (final Exception e) { LOG.warn("Exception caught while undoing dirty transactions. Remaining transactions " + "to be undone: " + runningTxns.size() + ". Aborting recovery to avoid possible damage. " + From 01e9078298f019c17719b272b5dc1fded72e7101 Mon Sep 17 00:00:00 2001 From: Adam Retter Date: Wed, 2 Oct 2024 21:36:15 +0200 Subject: [PATCH 7/8] [refactor] Hide the Journal Recovery progress bars when running the test suite so as not to pollute the output --- build/scripts/junit.xml | 14 ++++++++++++++ 1 file changed, 14 insertions(+) diff --git a/build/scripts/junit.xml b/build/scripts/junit.xml index 67c977efebf..8a0325b5130 100644 --- a/build/scripts/junit.xml +++ b/build/scripts/junit.xml @@ -40,6 +40,9 @@ depends="test-prepare, test-local, test-extensions, test-jetty, test-concurrent, test-remote, test-recovery, test-wrapup, test-ant" description="Run jUnit tests"/> + + + @@ -157,6 +160,7 @@ + @@ -261,6 +265,7 @@ + @@ -299,6 +304,7 @@ + @@ -328,6 +334,7 @@ + @@ -388,6 +395,7 @@ + @@ -424,6 +432,7 @@ + @@ -453,6 +462,7 @@ + @@ -522,6 +532,7 @@ + @@ -551,6 +562,7 @@ + @@ -591,6 +603,7 @@ + @@ -608,6 +621,7 @@ + From b2b0d61185d52f742d619b6edee2cf99a9094c07 Mon Sep 17 00:00:00 2001 From: Adam Retter Date: Thu, 3 Oct 2024 12:01:13 +0200 Subject: [PATCH 8/8] [bugfix] As these are plugins log a Warning and not an Error if the plugin is unavailable --- .../src/main/java/org/exist/plugin/PluginsManagerImpl.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/exist-core/src/main/java/org/exist/plugin/PluginsManagerImpl.java b/exist-core/src/main/java/org/exist/plugin/PluginsManagerImpl.java index 2aa06560139..f4fdeb1768c 100644 --- a/exist-core/src/main/java/org/exist/plugin/PluginsManagerImpl.java +++ b/exist-core/src/main/java/org/exist/plugin/PluginsManagerImpl.java @@ -236,7 +236,7 @@ public void addPlugin(final String className) { // NOTE: must set interrupted flag Thread.currentThread().interrupt(); } - LOG.error(e); + LOG.warn(e); } }