public void testPrimaryRelocationWithConcurrentIndexing() throws Exception { Path dataPath = createTempDir(); Settings nodeSettings = nodeSettings(dataPath); String node1 = internalCluster().startNode(nodeSettings); final String IDX = "test"; Settings idxSettings = Settings.builder() .put(IndexMetaData.SETTING_NUMBER_OF_SHARDS, 1) .put(IndexMetaData.SETTING_NUMBER_OF_REPLICAS, 1) .put(IndexMetaData.SETTING_DATA_PATH, dataPath.toAbsolutePath().toString()) .put(IndexMetaData.SETTING_SHADOW_REPLICAS, true) .put(IndexMetaData.SETTING_SHARED_FILESYSTEM, true) .build(); prepareCreate(IDX).setSettings(idxSettings).addMapping("doc", "foo", "type=text").get(); // Node1 has the primary, now node2 has the replica String node2 = internalCluster().startNode(nodeSettings); ensureGreen(IDX); flushAndRefresh(IDX); String node3 = internalCluster().startNode(nodeSettings); final AtomicInteger counter = new AtomicInteger(0); final CountDownLatch started = new CountDownLatch(1); final int numPhase1Docs = scaledRandomIntBetween(25, 200); final int numPhase2Docs = scaledRandomIntBetween(25, 200); final CountDownLatch phase1finished = new CountDownLatch(1); final CountDownLatch phase2finished = new CountDownLatch(1); final CopyOnWriteArrayList<Exception> exceptions = new CopyOnWriteArrayList<>(); Thread thread = new Thread() { @Override public void run() { started.countDown(); while (counter.get() < (numPhase1Docs + numPhase2Docs)) { try { final IndexResponse indexResponse = client() .prepareIndex(IDX, "doc", Integer.toString(counter.incrementAndGet())) .setSource("foo", "bar") .get(); assertEquals(DocWriteResponse.Result.CREATED, indexResponse.getResult()); } catch (Exception e) { exceptions.add(e); } final int docCount = counter.get(); if (docCount == numPhase1Docs) { phase1finished.countDown(); } } logger.info("--> stopping indexing thread"); phase2finished.countDown(); } }; thread.start(); started.await(); phase1finished.await(); // wait for a certain number of documents to be indexed logger.info("--> excluding {} from allocation", node1); // now prevent primary from being allocated on node 1 move to node_3 Settings build = Settings.builder().put("index.routing.allocation.exclude._name", node1).build(); client().admin().indices().prepareUpdateSettings(IDX).setSettings(build).execute().actionGet(); // wait for more documents to be indexed post-recovery, also waits for // indexing thread to stop phase2finished.await(); ExceptionsHelper.rethrowAndSuppress(exceptions); ensureGreen(IDX); thread.join(); logger.info("--> performing query"); flushAndRefresh(); SearchResponse resp = client().prepareSearch(IDX).setQuery(matchAllQuery()).get(); assertHitCount(resp, counter.get()); assertHitCount(resp, numPhase1Docs + numPhase2Docs); }
/** * Perform phase1 of the recovery operations. Once this {@link SnapshotIndexCommit} snapshot has * been performed no commit operations (files being fsync'd) are effectively allowed on this index * until all recovery phases are done * * <p>Phase1 examines the segment files on the target node and copies over the segments that are * missing. Only segments that have the same size and checksum can be reused * * <p>{@code InternalEngine#recover} is responsible for snapshotting the index and releasing the * snapshot once all 3 phases of recovery are complete */ @Override public void phase1(final SnapshotIndexCommit snapshot) throws ElasticsearchException { cancellableThreads.checkForCancel(); // Total size of segment files that are recovered long totalSize = 0; // Total size of segment files that were able to be re-used long existingTotalSize = 0; final Store store = shard.store(); store.incRef(); try { StopWatch stopWatch = new StopWatch().start(); final Store.MetadataSnapshot recoverySourceMetadata = store.getMetadata(snapshot); for (String name : snapshot.getFiles()) { final StoreFileMetaData md = recoverySourceMetadata.get(name); if (md == null) { logger.info( "Snapshot differs from actual index for file: {} meta: {}", name, recoverySourceMetadata.asMap()); throw new CorruptIndexException( "Snapshot differs from actual index - maybe index was removed metadata has " + recoverySourceMetadata.asMap().size() + " files"); } } String recoverySourceSyncId = recoverySourceMetadata.getSyncId(); String recoveryTargetSyncId = request.metadataSnapshot().getSyncId(); final boolean recoverWithSyncId = recoverySourceSyncId != null && recoverySourceSyncId.equals(recoveryTargetSyncId); if (recoverWithSyncId) { final long numDocsTarget = request.metadataSnapshot().getNumDocs(); final long numDocsSource = recoverySourceMetadata.getNumDocs(); if (numDocsTarget != numDocsSource) { throw new IllegalStateException( "try to recover " + request.shardId() + " from primary shard with sync id but number of docs differ: " + numDocsTarget + " (" + request.sourceNode().getName() + ", primary) vs " + numDocsSource + "(" + request.targetNode().getName() + ")"); } // we shortcut recovery here because we have nothing to copy. but we must still start the // engine on the target. // so we don't return here logger.trace( "[{}][{}] skipping [phase1] to {} - identical sync id [{}] found on both source and target", indexName, shardId, request.targetNode(), recoverySourceSyncId); } else { // Generate a "diff" of all the identical, different, and missing // segment files on the target node, using the existing files on // the source node final Store.RecoveryDiff diff = recoverySourceMetadata.recoveryDiff(request.metadataSnapshot()); for (StoreFileMetaData md : diff.identical) { response.phase1ExistingFileNames.add(md.name()); response.phase1ExistingFileSizes.add(md.length()); existingTotalSize += md.length(); if (logger.isTraceEnabled()) { logger.trace( "[{}][{}] recovery [phase1] to {}: not recovering [{}], exists in local store and has checksum [{}], size [{}]", indexName, shardId, request.targetNode(), md.name(), md.checksum(), md.length()); } totalSize += md.length(); } for (StoreFileMetaData md : Iterables.concat(diff.different, diff.missing)) { if (request.metadataSnapshot().asMap().containsKey(md.name())) { logger.trace( "[{}][{}] recovery [phase1] to {}: recovering [{}], exists in local store, but is different: remote [{}], local [{}]", indexName, shardId, request.targetNode(), md.name(), request.metadataSnapshot().get(md.name()), md); } else { logger.trace( "[{}][{}] recovery [phase1] to {}: recovering [{}], does not exists in remote", indexName, shardId, request.targetNode(), md.name()); } response.phase1FileNames.add(md.name()); response.phase1FileSizes.add(md.length()); totalSize += md.length(); } response.phase1TotalSize = totalSize; response.phase1ExistingTotalSize = existingTotalSize; logger.trace( "[{}][{}] recovery [phase1] to {}: recovering_files [{}] with total_size [{}], reusing_files [{}] with total_size [{}]", indexName, shardId, request.targetNode(), response.phase1FileNames.size(), new ByteSizeValue(totalSize), response.phase1ExistingFileNames.size(), new ByteSizeValue(existingTotalSize)); cancellableThreads.execute( new Interruptable() { @Override public void run() throws InterruptedException { RecoveryFilesInfoRequest recoveryInfoFilesRequest = new RecoveryFilesInfoRequest( request.recoveryId(), request.shardId(), response.phase1FileNames, response.phase1FileSizes, response.phase1ExistingFileNames, response.phase1ExistingFileSizes, shard.translog().estimatedNumberOfOperations(), response.phase1TotalSize, response.phase1ExistingTotalSize); transportService .submitRequest( request.targetNode(), RecoveryTarget.Actions.FILES_INFO, recoveryInfoFilesRequest, TransportRequestOptions.options() .withTimeout(recoverySettings.internalActionTimeout()), EmptyTransportResponseHandler.INSTANCE_SAME) .txGet(); } }); // This latch will be used to wait until all files have been transferred to the target node final CountDownLatch latch = new CountDownLatch(response.phase1FileNames.size()); final CopyOnWriteArrayList<Throwable> exceptions = new CopyOnWriteArrayList<>(); final AtomicReference<Throwable> corruptedEngine = new AtomicReference<>(); int fileIndex = 0; ThreadPoolExecutor pool; // How many bytes we've copied since we last called RateLimiter.pause final AtomicLong bytesSinceLastPause = new AtomicLong(); for (final String name : response.phase1FileNames) { long fileSize = response.phase1FileSizes.get(fileIndex); // Files are split into two categories, files that are "small" // (under 5mb) and other files. Small files are transferred // using a separate thread pool dedicated to small files. // // The idea behind this is that while we are transferring an // older, large index, a user may create a new index, but that // index will not be able to recover until the large index // finishes, by using two different thread pools we can allow // tiny files (like segments for a brand new index) to be // recovered while ongoing large segment recoveries are // happening. It also allows these pools to be configured // separately. if (fileSize > RecoverySettings.SMALL_FILE_CUTOFF_BYTES) { pool = recoverySettings.concurrentStreamPool(); } else { pool = recoverySettings.concurrentSmallFileStreamPool(); } pool.execute( new AbstractRunnable() { @Override public void onFailure(Throwable t) { // we either got rejected or the store can't be incremented / we are canceled logger.debug("Failed to transfer file [" + name + "] on recovery"); } public void onAfter() { // Signify this file has completed by decrementing the latch latch.countDown(); } @Override protected void doRun() { cancellableThreads.checkForCancel(); store.incRef(); final StoreFileMetaData md = recoverySourceMetadata.get(name); try (final IndexInput indexInput = store.directory().openInput(name, IOContext.READONCE)) { final int BUFFER_SIZE = (int) recoverySettings.fileChunkSize().bytes(); final byte[] buf = new byte[BUFFER_SIZE]; boolean shouldCompressRequest = recoverySettings.compress(); if (CompressorFactory.isCompressed(indexInput)) { shouldCompressRequest = false; } final long len = indexInput.length(); long readCount = 0; final TransportRequestOptions requestOptions = TransportRequestOptions.options() .withCompress(shouldCompressRequest) .withType(TransportRequestOptions.Type.RECOVERY) .withTimeout(recoverySettings.internalActionTimeout()); while (readCount < len) { if (shard.state() == IndexShardState.CLOSED) { // check if the shard got closed on us throw new IndexShardClosedException(shard.shardId()); } int toRead = readCount + BUFFER_SIZE > len ? (int) (len - readCount) : BUFFER_SIZE; final long position = indexInput.getFilePointer(); // Pause using the rate limiter, if desired, to throttle the recovery RateLimiter rl = recoverySettings.rateLimiter(); long throttleTimeInNanos = 0; if (rl != null) { long bytes = bytesSinceLastPause.addAndGet(toRead); if (bytes > rl.getMinPauseCheckBytes()) { // Time to pause bytesSinceLastPause.addAndGet(-bytes); throttleTimeInNanos = rl.pause(bytes); shard.recoveryStats().addThrottleTime(throttleTimeInNanos); } } indexInput.readBytes(buf, 0, toRead, false); final BytesArray content = new BytesArray(buf, 0, toRead); readCount += toRead; final boolean lastChunk = readCount == len; final RecoveryFileChunkRequest fileChunkRequest = new RecoveryFileChunkRequest( request.recoveryId(), request.shardId(), md, position, content, lastChunk, shard.translog().estimatedNumberOfOperations(), throttleTimeInNanos); cancellableThreads.execute( new Interruptable() { @Override public void run() throws InterruptedException { // Actually send the file chunk to the target node, waiting for it to // complete transportService .submitRequest( request.targetNode(), RecoveryTarget.Actions.FILE_CHUNK, fileChunkRequest, requestOptions, EmptyTransportResponseHandler.INSTANCE_SAME) .txGet(); } }); } } catch (Throwable e) { final Throwable corruptIndexException; if ((corruptIndexException = ExceptionsHelper.unwrapCorruption(e)) != null) { if (store.checkIntegrity(md) == false) { // we are corrupted on the primary -- fail! logger.warn( "{} Corrupted file detected {} checksum mismatch", shard.shardId(), md); if (corruptedEngine.compareAndSet(null, corruptIndexException) == false) { // if we are not the first exception, add ourselves as suppressed to the // main one: corruptedEngine.get().addSuppressed(e); } } else { // corruption has happened on the way to replica RemoteTransportException exception = new RemoteTransportException( "File corruption occurred on recovery but checksums are ok", null); exception.addSuppressed(e); exceptions.add(0, exception); // last exception first logger.warn( "{} Remote file corruption on node {}, recovering {}. local checksum OK", corruptIndexException, shard.shardId(), request.targetNode(), md); } } else { exceptions.add(0, e); // last exceptions first } } finally { store.decRef(); } } }); fileIndex++; } cancellableThreads.execute( new Interruptable() { @Override public void run() throws InterruptedException { // Wait for all files that need to be transferred to finish transferring latch.await(); } }); if (corruptedEngine.get() != null) { throw corruptedEngine.get(); } else { ExceptionsHelper.rethrowAndSuppress(exceptions); } cancellableThreads.execute( new Interruptable() { @Override public void run() throws InterruptedException { // Send the CLEAN_FILES request, which takes all of the files that // were transferred and renames them from their temporary file // names to the actual file names. It also writes checksums for // the files after they have been renamed. // // Once the files have been renamed, any other files that are not // related to this recovery (out of date segments, for example) // are deleted try { transportService .submitRequest( request.targetNode(), RecoveryTarget.Actions.CLEAN_FILES, new RecoveryCleanFilesRequest( request.recoveryId(), shard.shardId(), recoverySourceMetadata, shard.translog().estimatedNumberOfOperations()), TransportRequestOptions.options() .withTimeout(recoverySettings.internalActionTimeout()), EmptyTransportResponseHandler.INSTANCE_SAME) .txGet(); } catch (RemoteTransportException remoteException) { final IOException corruptIndexException; // we realized that after the index was copied and we wanted to finalize the // recovery // the index was corrupted: // - maybe due to a broken segments file on an empty index (transferred with no // checksum) // - maybe due to old segments without checksums or length only checks if ((corruptIndexException = ExceptionsHelper.unwrapCorruption(remoteException)) != null) { try { final Store.MetadataSnapshot recoverySourceMetadata = store.getMetadata(snapshot); StoreFileMetaData[] metadata = Iterables.toArray(recoverySourceMetadata, StoreFileMetaData.class); ArrayUtil.timSort( metadata, new Comparator<StoreFileMetaData>() { @Override public int compare(StoreFileMetaData o1, StoreFileMetaData o2) { return Long.compare( o1.length(), o2.length()); // check small files first } }); for (StoreFileMetaData md : metadata) { logger.debug( "{} checking integrity for file {} after remove corruption exception", shard.shardId(), md); if (store.checkIntegrity(md) == false) { // we are corrupted on the primary -- fail! logger.warn( "{} Corrupted file detected {} checksum mismatch", shard.shardId(), md); throw corruptIndexException; } } } catch (IOException ex) { remoteException.addSuppressed(ex); throw remoteException; } // corruption has happened on the way to replica RemoteTransportException exception = new RemoteTransportException( "File corruption occurred on recovery but checksums are ok", null); exception.addSuppressed(remoteException); logger.warn( "{} Remote file corruption during finalization on node {}, recovering {}. local checksum OK", corruptIndexException, shard.shardId(), request.targetNode()); throw exception; } else { throw remoteException; } } } }); } stopWatch.stop(); logger.trace( "[{}][{}] recovery [phase1] to {}: took [{}]", indexName, shardId, request.targetNode(), stopWatch.totalTime()); response.phase1Time = stopWatch.totalTime().millis(); } catch (Throwable e) { throw new RecoverFilesRecoveryException( request.shardId(), response.phase1FileNames.size(), new ByteSizeValue(totalSize), e); } finally { store.decRef(); } }