Skip to content

Commit

Permalink
Synchronizes slowlog json keys with beats (#74211)
Browse files Browse the repository at this point in the history
Filebeat ships with dedicated fields for Elasticsearch slowlog
This updates our ECS logger to report the slowlog keys under
elasticsearch.slowlog
This prevents clashes with ECS templates
  • Loading branch information
Mpdreamz authored Jun 21, 2021
1 parent 8904ffe commit 40b1dc0
Show file tree
Hide file tree
Showing 4 changed files with 43 additions and 43 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -155,12 +155,12 @@ public static ESLogMessage of(
private static Map<String, Object> prepareMap(Index index, ParsedDocument doc, long tookInNanos, boolean reformat,
int maxSourceCharsToLog) {
Map<String,Object> map = new HashMap<>();
map.put("message", index);
map.put("took", TimeValue.timeValueNanos(tookInNanos));
map.put("took_millis", ""+TimeUnit.NANOSECONDS.toMillis(tookInNanos));
map.put("id", doc.id());
map.put("elasticsearch.slowlog.message", index);
map.put("elasticsearch.slowlog.took", TimeValue.timeValueNanos(tookInNanos).toString());
map.put("elasticsearch.slowlog.took_millis", String.valueOf(TimeUnit.NANOSECONDS.toMillis(tookInNanos)));
map.put("elasticsearch.slowlog.id", doc.id());
if (doc.routing() != null) {
map.put("routing", doc.routing());
map.put("elasticsearch.slowlog.routing", doc.routing());
}

if (maxSourceCharsToLog == 0 || doc.source() == null || doc.source().length() == 0) {
Expand All @@ -171,11 +171,11 @@ private static Map<String, Object> prepareMap(Index index, ParsedDocument doc, l
String trim = Strings.cleanTruncate(source, maxSourceCharsToLog).trim();
StringBuilder sb = new StringBuilder(trim);
StringBuilders.escapeJson(sb,0);
map.put("source", sb.toString());
map.put("elasticsearch.slowlog.source", sb.toString());
} catch (IOException e) {
StringBuilder sb = new StringBuilder("_failed_to_convert_[" + e.getMessage()+"]");
StringBuilders.escapeJson(sb,0);
map.put("source", sb.toString());
map.put("elasticsearch.slowlog.source", sb.toString());
/*
* We choose to fail to write to the slow log and instead let this percolate up to the post index listener loop where this
* will be logged at the warn level.
Expand Down
22 changes: 11 additions & 11 deletions server/src/main/java/org/elasticsearch/index/SearchSlowLog.java
Original file line number Diff line number Diff line change
Expand Up @@ -141,28 +141,28 @@ public static ESLogMessage of(SearchContext context, long tookInNanos) {

private static Map<String, Object> prepareMap(SearchContext context, long tookInNanos) {
Map<String, Object> messageFields = new HashMap<>();
messageFields.put("message", context.indexShard().shardId());
messageFields.put("took", TimeValue.timeValueNanos(tookInNanos));
messageFields.put("took_millis", TimeUnit.NANOSECONDS.toMillis(tookInNanos));
messageFields.put("elasticsearch.slowlog.message", context.indexShard().shardId());
messageFields.put("elasticsearch.slowlog.took", TimeValue.timeValueNanos(tookInNanos).toString());
messageFields.put("elasticsearch.slowlog.took_millis", TimeUnit.NANOSECONDS.toMillis(tookInNanos));
if (context.queryResult().getTotalHits() != null) {
messageFields.put("total_hits", context.queryResult().getTotalHits());
messageFields.put("elasticsearch.slowlog.total_hits", context.queryResult().getTotalHits());
} else {
messageFields.put("total_hits", "-1");
messageFields.put("elasticsearch.slowlog.total_hits", "-1");
}
messageFields.put("stats", escapeJson(ESLogMessage.asJsonArray(
messageFields.put("elasticsearch.slowlog.stats", escapeJson(ESLogMessage.asJsonArray(
context.groupStats() != null ? context.groupStats().stream() : Stream.empty())));
messageFields.put("search_type", context.searchType());
messageFields.put("total_shards", context.numberOfShards());
messageFields.put("elasticsearch.slowlog.search_type", context.searchType());
messageFields.put("elasticsearch.slowlog.total_shards", context.numberOfShards());

if (context.request().source() != null) {
String source = escapeJson(context.request().source().toString(FORMAT_PARAMS));

messageFields.put("source", source);
messageFields.put("elasticsearch.slowlog.source", source);
} else {
messageFields.put("source", "{}");
messageFields.put("elasticsearch.slowlog.source", "{}");
}

messageFields.put("id", context.getTask().getHeader(Task.X_OPAQUE_ID));
messageFields.put("elasticsearch.slowlog.id", context.getTask().getHeader(Task.X_OPAQUE_ID));
return messageFields;
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -204,16 +204,16 @@ public void testSlowLogMessageHasJsonFields() throws IOException {
// Turning off document logging doesn't log source[]
ESLogMessage p = IndexingSlowLogMessage.of(index, pd, 10, true, 0);

assertThat(p.get("message"),equalTo("[foo/123]"));
assertThat(p.get("took"),equalTo("10nanos"));
assertThat(p.get("took_millis"),equalTo("0"));
assertThat(p.get("id"),equalTo("id"));
assertThat(p.get("routing"),equalTo("routingValue"));
assertThat(p.get("source"), is(emptyOrNullString()));
assertThat(p.get("elasticsearch.slowlog.message"),equalTo("[foo/123]"));
assertThat(p.get("elasticsearch.slowlog.took"),equalTo("10nanos"));
assertThat(p.get("elasticsearch.slowlog.took_millis"),equalTo("0"));
assertThat(p.get("elasticsearch.slowlog.id"),equalTo("id"));
assertThat(p.get("elasticsearch.slowlog.routing"),equalTo("routingValue"));
assertThat(p.get("elasticsearch.slowlog.source"), is(emptyOrNullString()));

// Turning on document logging logs the whole thing
p = IndexingSlowLogMessage.of(index, pd, 10, true, Integer.MAX_VALUE);
assertThat(p.get("source"), containsString("{\\\"foo\\\":\\\"bar\\\"}"));
assertThat(p.get("elasticsearch.slowlog.source"), containsString("{\\\"foo\\\":\\\"bar\\\"}"));
}

public void testEmptyRoutingField() throws IOException {
Expand All @@ -240,17 +240,17 @@ public void testSlowLogParsedDocumentPrinterSourceToLog() throws IOException {

// Turning on document logging logs the whole thing
p = IndexingSlowLogMessage.of(index, pd, 10, true, Integer.MAX_VALUE);
assertThat(p.get("source"), equalTo("{\\\"foo\\\":\\\"bar\\\"}"));
assertThat(p.get("elasticsearch.slowlog.source"), equalTo("{\\\"foo\\\":\\\"bar\\\"}"));

// And you can truncate the source
p = IndexingSlowLogMessage.of(index, pd, 10, true, 3);
assertThat(p.get("source"), equalTo("{\\\"f"));
assertThat(p.get("elasticsearch.slowlog.source"), equalTo("{\\\"f"));

// And you can truncate the source
p = IndexingSlowLogMessage.of(index, pd, 10, true, 3);
assertThat(p.get("source"), containsString("{\\\"f"));
assertThat(p.get("message"), startsWith("[foo/123]"));
assertThat(p.get("took"), containsString("10nanos"));
assertThat(p.get("elasticsearch.slowlog.source"), containsString("{\\\"f"));
assertThat(p.get("elasticsearch.slowlog.message"), startsWith("[foo/123]"));
assertThat(p.get("elasticsearch.slowlog.took"), containsString("10nanos"));

// Throwing a error if source cannot be converted
source = new BytesArray("invalid");
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -223,14 +223,14 @@ public void testSlowLogHasJsonFields() throws IOException {
SearchContext searchContext = searchContextWithSourceAndTask(index);
ESLogMessage p = SearchSlowLog.SearchSlowLogMessage.of(searchContext, 10);

assertThat(p.get("message"), equalTo("[foo][0]"));
assertThat(p.get("took"), equalTo("10nanos"));
assertThat(p.get("took_millis"), equalTo("0"));
assertThat(p.get("total_hits"), equalTo("-1"));
assertThat(p.get("stats"), equalTo("[]"));
assertThat(p.get("search_type"), Matchers.nullValue());
assertThat(p.get("total_shards"), equalTo("1"));
assertThat(p.get("source"), equalTo("{\\\"query\\\":{\\\"match_all\\\":{\\\"boost\\\":1.0}}}"));
assertThat(p.get("elasticsearch.slowlog.message"), equalTo("[foo][0]"));
assertThat(p.get("elasticsearch.slowlog.took"), equalTo("10nanos"));
assertThat(p.get("elasticsearch.slowlog.took_millis"), equalTo("0"));
assertThat(p.get("elasticsearch.slowlog.total_hits"), equalTo("-1"));
assertThat(p.get("elasticsearch.slowlog.stats"), equalTo("[]"));
assertThat(p.get("elasticsearch.slowlog.search_type"), Matchers.nullValue());
assertThat(p.get("elasticsearch.slowlog.total_shards"), equalTo("1"));
assertThat(p.get("elasticsearch.slowlog.source"), equalTo("{\\\"query\\\":{\\\"match_all\\\":{\\\"boost\\\":1.0}}}"));
}


Expand All @@ -243,25 +243,25 @@ public void testSlowLogsWithStats() throws IOException {
Collections.singletonMap(Task.X_OPAQUE_ID, "my_id")));

ESLogMessage p = SearchSlowLog.SearchSlowLogMessage.of(searchContext, 10);
assertThat(p.get("stats"), equalTo("[\\\"group1\\\"]"));
assertThat(p.get("elasticsearch.slowlog.stats"), equalTo("[\\\"group1\\\"]"));

searchContext = createSearchContext(index, "group1", "group2");
source = SearchSourceBuilder.searchSource().query(QueryBuilders.matchAllQuery());
searchContext.request().source(source);
searchContext.setTask(new SearchShardTask(0, "n/a", "n/a", "test", null,
Collections.singletonMap(Task.X_OPAQUE_ID, "my_id")));
p = SearchSlowLog.SearchSlowLogMessage.of(searchContext, 10);
assertThat(p.get("stats"), equalTo("[\\\"group1\\\", \\\"group2\\\"]"));
assertThat(p.get("elasticsearch.slowlog.stats"), equalTo("[\\\"group1\\\", \\\"group2\\\"]"));
}

public void testSlowLogSearchContextPrinterToLog() throws IOException {
IndexService index = createIndex("foo");
SearchContext searchContext = searchContextWithSourceAndTask(index);
ESLogMessage p = SearchSlowLog.SearchSlowLogMessage.of(searchContext, 10);
assertThat(p.get("message"), equalTo("[foo][0]"));
assertThat(p.get("elasticsearch.slowlog.message"), equalTo("[foo][0]"));
// Makes sure that output doesn't contain any new lines
assertThat(p.get("source"), not(containsString("\n")));
assertThat(p.get("id"), equalTo("my_id"));
assertThat(p.get("elasticsearch.slowlog.source"), not(containsString("\n")));
assertThat(p.get("elasticsearch.slowlog.id"), equalTo("my_id"));
}

public void testSetQueryLevels() {
Expand Down

0 comments on commit 40b1dc0

Please sign in to comment.