diff --git a/src/main/java/org/elasticsearch/common/lucene/LoggerInfoStream.java b/src/main/java/org/elasticsearch/common/lucene/LoggerInfoStream.java index 7d8008b0fb7..1e8c08b2c34 100644 --- a/src/main/java/org/elasticsearch/common/lucene/LoggerInfoStream.java +++ b/src/main/java/org/elasticsearch/common/lucene/LoggerInfoStream.java @@ -26,23 +26,38 @@ import org.elasticsearch.common.settings.Settings; import org.elasticsearch.index.shard.ShardId; /** An InfoStream (for Lucene's IndexWriter) that redirects - * messages to Logger.trace. */ + * messages to "lucene.iw.ifd" and "lucene.iw" Logger.trace. */ public final class LoggerInfoStream extends InfoStream { + /** Used for component-specific logging: */ + + /** Logger for everything */ private final ESLogger logger; + /** Logger for IndexFileDeleter */ + private final ESLogger ifdLogger; + public LoggerInfoStream(Settings settings, ShardId shardId) { logger = Loggers.getLogger("lucene.iw", settings, shardId); + ifdLogger = Loggers.getLogger("lucene.iw.ifd", settings, shardId); } public void message(String component, String message) { - logger.trace("{} {}: {}", Thread.currentThread().getName(), component, message); + getLogger(component).trace("{} {}: {}", Thread.currentThread().getName(), component, message); } public boolean isEnabled(String component) { // TP is a special "test point" component; we don't want // to log it: - return logger.isTraceEnabled() && component.equals("TP") == false; + return getLogger(component).isTraceEnabled() && component.equals("TP") == false; + } + + private ESLogger getLogger(String component) { + if (component.equals("IFD")) { + return ifdLogger; + } else { + return logger; + } } @Override diff --git a/src/main/java/org/elasticsearch/index/snapshots/blobstore/BlobStoreIndexShardRepository.java b/src/main/java/org/elasticsearch/index/snapshots/blobstore/BlobStoreIndexShardRepository.java index 6038ab62251..e6f5ed0276a 100644 --- a/src/main/java/org/elasticsearch/index/snapshots/blobstore/BlobStoreIndexShardRepository.java +++ b/src/main/java/org/elasticsearch/index/snapshots/blobstore/BlobStoreIndexShardRepository.java @@ -806,6 +806,7 @@ public class BlobStoreIndexShardRepository extends AbstractComponent implements for (String storeFile : store.directory().listAll()) { if (!Store.isChecksum(storeFile) && !snapshot.containPhysicalIndexFile(storeFile)) { try { + store.logDeleteFile("restore", storeFile); store.directory().deleteFile(storeFile); } catch (IOException e) { // ignore diff --git a/src/main/java/org/elasticsearch/index/store/Store.java b/src/main/java/org/elasticsearch/index/store/Store.java index 678b6a17be2..95b20639575 100644 --- a/src/main/java/org/elasticsearch/index/store/Store.java +++ b/src/main/java/org/elasticsearch/index/store/Store.java @@ -537,8 +537,11 @@ public class Store extends AbstractIndexShardComponent implements Closeable, Ref */ public final class StoreDirectory extends FilterDirectory { + public final ESLogger deletesLogger; + StoreDirectory(Directory delegateDirectory) throws IOException { super(delegateDirectory); + deletesLogger = Loggers.getLogger("index.store.deletes", indexSettings, shardId); } public ShardId shardId() { @@ -551,6 +554,12 @@ public class Store extends AbstractIndexShardComponent implements Closeable, Ref assert false : "Nobody should close this directory except of the Store itself"; } + @Override + public void deleteFile(String name) throws IOException { + logDeleteFile("StoreDirectory.deleteFile", name); + super.deleteFile(name); + } + private void innerClose() throws IOException { super.close(); } @@ -561,8 +570,22 @@ public class Store extends AbstractIndexShardComponent implements Closeable, Ref } } + /** Log that we are about to delete this file, to the index.store.deletes component. */ + public void logDeleteFile(String message, String fileName) { + logDeleteFile(directory(), message, fileName); + } + + /** Log that we are about to delete this file, to the index.store.deletes component. */ + public static void logDeleteFile(Directory dir, String message, String fileName) { + assert dir instanceof StoreDirectory; + if (dir instanceof StoreDirectory) { + ((StoreDirectory) dir).deletesLogger.trace("{}: delete file {}", message, fileName); + } + // else what to do...? + } + /** - * Represents a snaphshot of the current directory build from the latest Lucene commit. + * Represents a snapshot of the current directory build from the latest Lucene commit. * Only files that are part of the last commit are considered in this datastrucutre. * For backwards compatibility the snapshot might include legacy checksums that * are derived from a dedicated checksum file written by older elasticsearch version pre 1.3 diff --git a/src/main/java/org/elasticsearch/indices/recovery/RecoveryTarget.java b/src/main/java/org/elasticsearch/indices/recovery/RecoveryTarget.java index e69db95a175..99cb2e7dd6e 100644 --- a/src/main/java/org/elasticsearch/indices/recovery/RecoveryTarget.java +++ b/src/main/java/org/elasticsearch/indices/recovery/RecoveryTarget.java @@ -385,6 +385,7 @@ public class RecoveryTarget extends AbstractComponent { // don't delete snapshot file, or the checksums file (note, this is extra protection since the Store won't delete checksum) if (!request.snapshotFiles().contains(existingFile) && !Store.isChecksum(existingFile)) { try { + store.logDeleteFile("recovery CleanFilesRequestHandler", existingFile); store.directory().deleteFile(existingFile); } catch (Exception e) { // ignore, we don't really care, will get deleted later on diff --git a/src/test/java/org/elasticsearch/index/engine/internal/InternalEngineIntegrationTest.java b/src/test/java/org/elasticsearch/index/engine/internal/InternalEngineIntegrationTest.java index e325a46494f..33f3e328f42 100644 --- a/src/test/java/org/elasticsearch/index/engine/internal/InternalEngineIntegrationTest.java +++ b/src/test/java/org/elasticsearch/index/engine/internal/InternalEngineIntegrationTest.java @@ -57,6 +57,8 @@ public class InternalEngineIntegrationTest extends ElasticsearchIntegrationTest private void assertTotalCompoundSegments(int i, int t, String index) { IndicesSegmentResponse indicesSegmentResponse = client().admin().indices().prepareSegments(index).get(); IndexSegments indexSegments = indicesSegmentResponse.getIndices().get(index); + assertNotNull(indexSegments); + assertNotNull(indexSegments.getShards()); Collection values = indexSegments.getShards().values(); int compounds = 0; int total = 0; diff --git a/src/test/java/org/elasticsearch/index/engine/internal/InternalEngineTests.java b/src/test/java/org/elasticsearch/index/engine/internal/InternalEngineTests.java index 661affecc3b..1b2e71f1055 100644 --- a/src/test/java/org/elasticsearch/index/engine/internal/InternalEngineTests.java +++ b/src/test/java/org/elasticsearch/index/engine/internal/InternalEngineTests.java @@ -1253,27 +1253,30 @@ public class InternalEngineTests extends ElasticsearchTestCase { } private static class MockAppender extends AppenderSkeleton { - public boolean sawIndexWriterMessage; + public boolean sawIndexWriterMessage; + public boolean sawIndexWriterIFDMessage; - @Override - protected void append(LoggingEvent event) { - if (event.getLevel() == Level.TRACE && - event.getLoggerName().endsWith("lucene.iw") && - event.getMessage().toString().contains("IW: apply all deletes during flush") && - event.getMessage().toString().contains("[index][1] ")) { - - sawIndexWriterMessage = true; + @Override + protected void append(LoggingEvent event) { + if (event.getLevel() == Level.TRACE && event.getMessage().toString().contains("[index][1] ")) { + if (event.getLoggerName().endsWith("lucene.iw") && + event.getMessage().toString().contains("IW: apply all deletes during flush")) { + sawIndexWriterMessage = true; + } + if (event.getLoggerName().endsWith("lucene.iw.ifd")) { + sawIndexWriterIFDMessage = true; + } + } } - } - @Override - public boolean requiresLayout() { - return false; - } + @Override + public boolean requiresLayout() { + return false; + } - @Override - public void close() { - } + @Override + public void close() { + } } // #5891: make sure IndexWriter's infoStream output is @@ -1307,6 +1310,36 @@ public class InternalEngineTests extends ElasticsearchTestCase { } } + // #8603: make sure we can separately log IFD's messages + public void testIndexWriterIFDInfoStream() { + MockAppender mockAppender = new MockAppender(); + + Logger iwIFDLogger = Logger.getLogger("lucene.iw.ifd"); + Level savedLevel = iwIFDLogger.getLevel(); + iwIFDLogger.addAppender(mockAppender); + iwIFDLogger.setLevel(Level.DEBUG); + + try { + // First, with DEBUG, which should NOT log IndexWriter output: + ParsedDocument doc = testParsedDocument("1", "1", "test", null, -1, -1, testDocumentWithTextField(), Lucene.STANDARD_ANALYZER, B_1, false); + engine.create(new Engine.Create(null, newUid("1"), doc)); + engine.flush(new Engine.Flush()); + assertFalse(mockAppender.sawIndexWriterMessage); + assertFalse(mockAppender.sawIndexWriterIFDMessage); + + // Again, with TRACE, which should only log IndexWriter IFD output: + iwIFDLogger.setLevel(Level.TRACE); + engine.create(new Engine.Create(null, newUid("2"), doc)); + engine.flush(new Engine.Flush()); + assertFalse(mockAppender.sawIndexWriterMessage); + assertTrue(mockAppender.sawIndexWriterIFDMessage); + + } finally { + iwIFDLogger.removeAppender(mockAppender); + iwIFDLogger.setLevel(null); + } + } + @Slow @Test public void testEnableGcDeletes() throws Exception {