From 98249507cff3e363ecb4c5f06f14f0bb96da1ad5 Mon Sep 17 00:00:00 2001 From: Simon Willnauer Date: Wed, 9 Mar 2016 09:38:46 +0100 Subject: [PATCH] Add missing index name to indexing slow log This was lost in refactoring even on the 2.x branch. The slow-log is not per index not per shard anymore such that we don't add the shard ID as the logger prefix. This commit adds back the index name as part of the logging message not as a prefix on the logger for better testabilitly. Closes #17025 --- .../org/elasticsearch/index/IndexingSlowLog.java | 15 ++++++++++----- .../elasticsearch/index/IndexingSlowLogTests.java | 14 ++++++++++---- 2 files changed, 20 insertions(+), 9 deletions(-) diff --git a/core/src/main/java/org/elasticsearch/index/IndexingSlowLog.java b/core/src/main/java/org/elasticsearch/index/IndexingSlowLog.java index 5452daa7f07..75d3d60daad 100644 --- a/core/src/main/java/org/elasticsearch/index/IndexingSlowLog.java +++ b/core/src/main/java/org/elasticsearch/index/IndexingSlowLog.java @@ -36,6 +36,7 @@ import java.util.concurrent.TimeUnit; /** */ public final class IndexingSlowLog implements IndexingOperationListener { + private final Index index; private boolean reformat; private long indexWarnThreshold; private long indexInfoThreshold; @@ -85,6 +86,7 @@ public final class IndexingSlowLog implements IndexingOperationListener { IndexingSlowLog(IndexSettings indexSettings, ESLogger indexLogger, ESLogger deleteLogger) { this.indexLogger = indexLogger; this.deleteLogger = deleteLogger; + this.index = indexSettings.getIndex(); indexSettings.getScopedSettings().addSettingsUpdateConsumer(INDEX_INDEXING_SLOWLOG_REFORMAT_SETTING, this::setReformat); this.reformat = indexSettings.getValue(INDEX_INDEXING_SLOWLOG_REFORMAT_SETTING); @@ -141,13 +143,13 @@ public final class IndexingSlowLog implements IndexingOperationListener { private void postIndexing(ParsedDocument doc, long tookInNanos) { if (indexWarnThreshold >= 0 && tookInNanos > indexWarnThreshold) { - indexLogger.warn("{}", new SlowLogParsedDocumentPrinter(doc, tookInNanos, reformat, maxSourceCharsToLog)); + indexLogger.warn("{}", new SlowLogParsedDocumentPrinter(index, doc, tookInNanos, reformat, maxSourceCharsToLog)); } else if (indexInfoThreshold >= 0 && tookInNanos > indexInfoThreshold) { - indexLogger.info("{}", new SlowLogParsedDocumentPrinter(doc, tookInNanos, reformat, maxSourceCharsToLog)); + indexLogger.info("{}", new SlowLogParsedDocumentPrinter(index, doc, tookInNanos, reformat, maxSourceCharsToLog)); } else if (indexDebugThreshold >= 0 && tookInNanos > indexDebugThreshold) { - indexLogger.debug("{}", new SlowLogParsedDocumentPrinter(doc, tookInNanos, reformat, maxSourceCharsToLog)); + indexLogger.debug("{}", new SlowLogParsedDocumentPrinter(index, doc, tookInNanos, reformat, maxSourceCharsToLog)); } else if (indexTraceThreshold >= 0 && tookInNanos > indexTraceThreshold) { - indexLogger.trace("{}", new SlowLogParsedDocumentPrinter(doc, tookInNanos, reformat, maxSourceCharsToLog)); + indexLogger.trace("{}", new SlowLogParsedDocumentPrinter(index, doc, tookInNanos, reformat, maxSourceCharsToLog)); } } @@ -156,9 +158,11 @@ public final class IndexingSlowLog implements IndexingOperationListener { private final long tookInNanos; private final boolean reformat; private final int maxSourceCharsToLog; + private final Index index; - SlowLogParsedDocumentPrinter(ParsedDocument doc, long tookInNanos, boolean reformat, int maxSourceCharsToLog) { + SlowLogParsedDocumentPrinter(Index index, ParsedDocument doc, long tookInNanos, boolean reformat, int maxSourceCharsToLog) { this.doc = doc; + this.index = index; this.tookInNanos = tookInNanos; this.reformat = reformat; this.maxSourceCharsToLog = maxSourceCharsToLog; @@ -167,6 +171,7 @@ public final class IndexingSlowLog implements IndexingOperationListener { @Override public String toString() { StringBuilder sb = new StringBuilder(); + sb.append(index).append(" "); sb.append("took[").append(TimeValue.timeValueNanos(tookInNanos)).append("], took_millis[").append(TimeUnit.NANOSECONDS.toMillis(tookInNanos)).append("], "); sb.append("type[").append(doc.type()).append("], "); sb.append("id[").append(doc.id()).append("], "); diff --git a/core/src/test/java/org/elasticsearch/index/IndexingSlowLogTests.java b/core/src/test/java/org/elasticsearch/index/IndexingSlowLogTests.java index e3676366511..9e05122322a 100644 --- a/core/src/test/java/org/elasticsearch/index/IndexingSlowLogTests.java +++ b/core/src/test/java/org/elasticsearch/index/IndexingSlowLogTests.java @@ -36,24 +36,30 @@ import java.io.IOException; import static org.hamcrest.Matchers.containsString; import static org.hamcrest.Matchers.not; +import static org.hamcrest.Matchers.startsWith; public class IndexingSlowLogTests extends ESTestCase { public void testSlowLogParsedDocumentPrinterSourceToLog() throws IOException { BytesReference source = JsonXContent.contentBuilder().startObject().field("foo", "bar").endObject().bytes(); ParsedDocument pd = new ParsedDocument(new StringField("uid", "test:id", Store.YES), new LegacyIntField("version", 1, Store.YES), "id", "test", null, 0, -1, null, source, null); - + Index index = new Index("foo", "123"); // Turning off document logging doesn't log source[] - SlowLogParsedDocumentPrinter p = new SlowLogParsedDocumentPrinter(pd, 10, true, 0); + SlowLogParsedDocumentPrinter p = new SlowLogParsedDocumentPrinter(index, pd, 10, true, 0); assertThat(p.toString(), not(containsString("source["))); // Turning on document logging logs the whole thing - p = new SlowLogParsedDocumentPrinter(pd, 10, true, Integer.MAX_VALUE); + p = new SlowLogParsedDocumentPrinter(index, pd, 10, true, Integer.MAX_VALUE); assertThat(p.toString(), containsString("source[{\"foo\":\"bar\"}]")); // And you can truncate the source - p = new SlowLogParsedDocumentPrinter(pd, 10, true, 3); + p = new SlowLogParsedDocumentPrinter(index, pd, 10, true, 3); assertThat(p.toString(), containsString("source[{\"f]")); + + // And you can truncate the source + p = new SlowLogParsedDocumentPrinter(index, pd, 10, true, 3); + assertThat(p.toString(), containsString("source[{\"f]")); + assertThat(p.toString(), startsWith("[foo/123] took")); } public void testReformatSetting() {