-
Notifications
You must be signed in to change notification settings - Fork 852
SOLR-18344: Report in-progress backup status on /replication?command=details #4728
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: main
Are you sure you want to change the base?
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,9 @@ | ||
| # See https://github.com/apache/solr/blob/main/dev-docs/changelog.adoc | ||
| title: /replication?command=details now reports a backup while it is still running, with file counts, instead of showing the previous backup's status until the new one completes | ||
| type: fixed # added, changed, fixed, deprecated, removed, dependency_update, security, other | ||
| authors: | ||
| - name: Idan Tepper | ||
| nick: idantepper | ||
| links: | ||
| - name: SOLR-18344 | ||
| url: https://issues.apache.org/jira/browse/SOLR-18344 | ||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -66,6 +66,12 @@ public class SnapShooter { | |
| private BackupRepository backupRepo = null; | ||
| private String commitName; // can be null | ||
|
|
||
| /** | ||
| * Receives in-progress status while the snapshot is being created, so that it can be reported | ||
| * before the snapshot completes. A no-op unless set by {@link #createSnapAsync}. | ||
| */ | ||
| private volatile Consumer<NamedList<?>> progressListener = nl -> {}; | ||
|
|
||
| public SnapShooter( | ||
| BackupRepository backupRepo, | ||
| SolrCore core, | ||
|
|
@@ -228,7 +234,42 @@ public static IndexCommit getAndSaveNamedIndexCommit(SolrCore solrCore, String c | |
| + solrCore.getName()); | ||
| } | ||
|
|
||
| /** | ||
| * The status of a snapshot that has been requested but has not finished yet. A null {@link | ||
| * #snapshotName} is omitted rather than reported, matching how {@link CoreSnapshotResponse} | ||
| * reports the same snapshot once it has completed. | ||
| */ | ||
| private NamedList<Object> inProgressDetails(String startTime, String status) { | ||
| NamedList<Object> details = new SimpleOrderedMap<>(); | ||
| details.add("startTime", startTime); | ||
| details.add("status", status); | ||
| if (snapshotName != null) { | ||
| details.add("snapshotName", snapshotName); | ||
| } | ||
| details.add("directoryName", directoryName); | ||
| return details; | ||
| } | ||
|
|
||
| /** | ||
| * The status of a snapshot whose files are being copied. Only reported once the index commit has | ||
| * been resolved, since until then there is no file list to count. | ||
| * | ||
| * @param fileCount the total number of files this snapshot will copy | ||
| * @param finishedFileCount how many of them have been copied so far | ||
| */ | ||
| private NamedList<Object> runningDetails(String startTime, int fileCount, int finishedFileCount) { | ||
| NamedList<Object> details = inProgressDetails(startTime, RUNNING_STATUS); | ||
| details.add("fileCount", fileCount); | ||
| details.add("finishedFileCount", finishedFileCount); | ||
| return details; | ||
| } | ||
|
|
||
| public void createSnapAsync(final int numberToKeep, Consumer<NamedList<?>> result) { | ||
| this.progressListener = result; | ||
| // Report before the thread starts, otherwise the previously reported status (possibly a | ||
| // "success" from an earlier snapshot) stays visible until the index commit has been resolved. | ||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. so is the idea that a success is just going to hangaround for forever, or until the next snapshot is begun? I guess that is how it works...
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Yes, exactly that. That lifetime is pre-existing and this PR does not change it. What it changes is when the first overwrite lands: it used to be at the end of the next backup, so a stale You prompted me to go look at the docs, and my checklist claim was wrong: Drive-by in the same section, shout if you would rather it went separately: it said a failure reports |
||
| // The file list isn't known until then, so this status carries no file counts. | ||
| result.accept(inProgressDetails(Instant.now().toString(), WAITING_FOR_COMMIT_STATUS)); | ||
| // TODO should use Solr's ExecutorUtil | ||
| new Thread( | ||
| () -> { | ||
|
|
@@ -277,6 +318,7 @@ protected CoreSnapshotResponse createSnapshot(final IndexCommit indexCommit) thr | |
| details.startTime = Instant.now().toString(); | ||
|
|
||
| Collection<String> files = indexCommit.getFileNames(); | ||
| progressListener.accept(runningDetails(details.startTime, files.size(), 0)); | ||
| Directory dir = | ||
| solrCore | ||
| .getDirectoryFactory() | ||
|
|
@@ -285,10 +327,13 @@ protected CoreSnapshotResponse createSnapshot(final IndexCommit indexCommit) thr | |
| DirContext.DEFAULT, | ||
| solrCore.getSolrConfig().indexConfig.lockType); | ||
| try { | ||
| int finishedFileCount = 0; | ||
| for (String fileName : files) { | ||
| log.debug( | ||
| "Copying fileName={} from dir={} to snapshot={}", fileName, dir, snapshotDirPath); | ||
| backupRepo.copyFileFrom(dir, fileName, snapshotDirPath); | ||
| progressListener.accept( | ||
| runningDetails(details.startTime, files.size(), ++finishedFileCount)); | ||
| } | ||
| } finally { | ||
| solrCore.getDirectoryFactory().release(dir); | ||
|
|
@@ -376,6 +421,15 @@ protected void deleteNamedSnapshot(ReplicationHandler replicationHandler) { | |
|
|
||
| public static final String DATE_FMT = "yyyyMMddHHmmssSSS"; | ||
|
|
||
| /** | ||
| * Status reported after a snapshot has been requested but before its index commit -- and with it | ||
| * the list of files to copy -- has been resolved. | ||
| */ | ||
| public static final String WAITING_FOR_COMMIT_STATUS = "waiting for commit"; | ||
|
|
||
| /** Status reported while a snapshot's files are being copied. */ | ||
| public static final String RUNNING_STATUS = "running"; | ||
|
|
||
| public static class CoreSnapshotResponse extends SolrJerseyResponse { | ||
| @Schema(description = "The time at which snapshot started at.") | ||
| @JsonProperty("startTime") | ||
|
|
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -20,6 +20,9 @@ | |
| import java.nio.file.Files; | ||
| import java.nio.file.Path; | ||
| import java.util.Arrays; | ||
| import java.util.List; | ||
| import java.util.concurrent.CopyOnWriteArrayList; | ||
| import java.util.concurrent.TimeUnit; | ||
| import org.apache.lucene.index.CheckIndex; | ||
| import org.apache.lucene.index.DirectoryReader; | ||
| import org.apache.lucene.index.IndexCommit; | ||
|
|
@@ -29,9 +32,12 @@ | |
| import org.apache.lucene.tests.util.TestUtil; | ||
| import org.apache.solr.SolrTestCaseJ4; | ||
| import org.apache.solr.common.params.CoreAdminParams; | ||
| import org.apache.solr.common.util.NamedList; | ||
| import org.apache.solr.common.util.TimeSource; | ||
| import org.apache.solr.core.CoreContainer; | ||
| import org.apache.solr.handler.admin.CoreAdminHandler; | ||
| import org.apache.solr.response.SolrQueryResponse; | ||
| import org.apache.solr.util.TimeOut; | ||
| import org.junit.After; | ||
| import org.junit.Before; | ||
|
|
||
|
|
@@ -369,6 +375,101 @@ public void testBackupAfterSoftCommit() throws Exception { | |
| admin.close(); | ||
| } | ||
|
|
||
| /** | ||
| * Backups run asynchronously, so the status reported to /replication?command=details must | ||
| * describe a snapshot that is still running -- not stay silent (or keep describing the previously | ||
| * completed snapshot) until it finishes. | ||
| * | ||
| * <p>Rather than racing a live backup by polling "details", this collects every status the | ||
| * handler would have published and asserts on the whole sequence, which is deterministic. | ||
| */ | ||
| public void testBackupReportsProgressWhileRunning() throws Exception { | ||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. is this a pattern that we follow elsewhere in Solr for these types of things?
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Yes -- Solr has a family of "record what the code published, then assert on the collected sequence" helpers rather than racing the thing under test. The three closest to this one:
The alternative would have been Worth recording that the new statuses do not disturb that helper either -- non- Happy to add an HTTP-level assertion on top if you would prefer one, though it could only assert "not Unrelated: the red check is |
||
| for (int i = 0; i < 50; i++) { | ||
| assertU(adoc("id", String.valueOf(i))); | ||
| } | ||
| assertU(commit()); | ||
|
|
||
| final Path backupDir = createTempDir(); | ||
| h.getCoreContainer().getAllowPaths().add(backupDir); | ||
|
|
||
| // this is what /replication?command=backup does, minus the http plumbing | ||
| final List<NamedList<?>> reports = new CopyOnWriteArrayList<>(); | ||
| ReplicationHandler.doSnapShoot( | ||
| 0, 0, backupDir.toString(), null, null, "progress_backup", h.getCore(), reports::add); | ||
|
|
||
| final TimeOut timeOut = new TimeOut(60, TimeUnit.SECONDS, TimeSource.NANO_TIME); | ||
| NamedList<?> last = null; | ||
| while (!timeOut.hasTimedOut()) { | ||
| if (!reports.isEmpty()) { | ||
| last = reports.get(reports.size() - 1); | ||
| assertNull("Backup failed: " + last, last.get("exception")); | ||
| if ("success".equals(last.get("status"))) { | ||
| break; | ||
| } | ||
| } | ||
| timeOut.sleep(20); | ||
| } | ||
| assertNotNull("No backup status was ever reported", last); | ||
| assertEquals( | ||
| "Backup did not succeed before the TimeOut elapsed: " + last, | ||
| "success", | ||
| last.get("status")); | ||
| // the backup is over, so no further reports can arrive and 'reports' is now stable | ||
| final int totalFileCount = ((Number) last.get("fileCount")).intValue(); | ||
| assertTrue( | ||
| "Test needs a backup of more than one file, got " + totalFileCount, 1 < totalFileCount); | ||
|
|
||
| // the very first status is published before the index commit is resolved, so it names no files | ||
| final NamedList<?> waiting = reports.get(0); | ||
| assertEquals( | ||
| "backup should first report itself as waiting: " + waiting, | ||
| SnapShooter.WAITING_FOR_COMMIT_STATUS, | ||
| waiting.get("status")); | ||
| assertNull("no file list is known yet: " + waiting, waiting.get("fileCount")); | ||
| assertNull("no file list is known yet: " + waiting, waiting.get("finishedFileCount")); | ||
|
|
||
| final List<NamedList<?>> running = reports.subList(1, reports.size() - 1); | ||
| assertFalse("Backup was never reported as running", running.isEmpty()); | ||
|
|
||
| int previousFinished = -1; | ||
| for (NamedList<?> report : running) { | ||
| assertEquals( | ||
| "not reported as running: " + report, SnapShooter.RUNNING_STATUS, report.get("status")); | ||
|
|
||
| final int finished = ((Number) report.get("finishedFileCount")).intValue(); | ||
| assertTrue( | ||
| "finishedFileCount went backwards: " + previousFinished + " -> " + finished, | ||
| previousFinished <= finished); | ||
| previousFinished = finished; | ||
| } | ||
|
|
||
| // every in-progress status must identify the backup it is about | ||
| for (NamedList<?> report : reports.subList(0, reports.size() - 1)) { | ||
| assertNotNull("in-progress report has no startTime: " + report, report.get("startTime")); | ||
| assertEquals( | ||
| "in-progress report names the wrong snapshot: " + report, | ||
| "progress_backup", | ||
| report.get("snapshotName")); | ||
| assertEquals( | ||
| "in-progress report has the wrong directoryName: " + report, | ||
| "snapshot.progress_backup", | ||
| report.get("directoryName")); | ||
| } | ||
|
|
||
| // by the last report before completion, every file must be accounted for | ||
| final NamedList<?> lastRunning = running.get(running.size() - 1); | ||
| assertEquals( | ||
| "last running report disagrees with the completed backup: " + lastRunning, | ||
| totalFileCount, | ||
| ((Number) lastRunning.get("fileCount")).intValue()); | ||
| assertEquals( | ||
| "last running report did not finish every file: " + lastRunning, | ||
| totalFileCount, | ||
| ((Number) lastRunning.get("finishedFileCount")).intValue()); | ||
|
|
||
| simpleBackupCheck(backupDir.resolve("snapshot.progress_backup"), 50); | ||
| } | ||
|
|
||
| /** | ||
| * A simple sanity check that asserts the current weird behavior of | ||
| * DirectoryReader.openIfChanged() and demos how 'softCommit' can cause the IndexReader in use by | ||
|
|
||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
"repots backup details" maybe?