Skip to content
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

Refactor ESLogMessage to not define fields upfront #46702

Merged
merged 17 commits into from
Oct 10, 2019
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,6 @@ appender.deprecation_rolling.type = Console
appender.deprecation_rolling.name = deprecation_rolling
appender.deprecation_rolling.layout.type = ESJsonLayout
appender.deprecation_rolling.layout.type_name = deprecation
appender.deprecation_rolling.layout.esmessagefields=x-opaque-id

logger.deprecation.name = org.elasticsearch.deprecation
logger.deprecation.level = warn
Expand All @@ -27,7 +26,7 @@ appender.index_search_slowlog_rolling.type = Console
appender.index_search_slowlog_rolling.name = index_search_slowlog_rolling
appender.index_search_slowlog_rolling.layout.type = ESJsonLayout
appender.index_search_slowlog_rolling.layout.type_name = index_search_slowlog
appender.index_search_slowlog_rolling.layout.esmessagefields=message,took,took_millis,total_hits,stats,search_type,total_shards,source,id
appender.index_search_slowlog_rolling.layout.overrideFields=message

logger.index_search_slowlog_rolling.name = index.search.slowlog
logger.index_search_slowlog_rolling.level = trace
Expand All @@ -38,7 +37,7 @@ appender.index_indexing_slowlog_rolling.type = Console
appender.index_indexing_slowlog_rolling.name = index_indexing_slowlog_rolling
appender.index_indexing_slowlog_rolling.layout.type = ESJsonLayout
appender.index_indexing_slowlog_rolling.layout.type_name = index_indexing_slowlog
appender.index_indexing_slowlog_rolling.layout.esmessagefields=message,took,took_millis,doc_type,id,routing,source
appender.index_indexing_slowlog_rolling.layout.overrideFields=message

logger.index_indexing_slowlog.name = index.indexing.slowlog.index
logger.index_indexing_slowlog.level = trace
Expand Down
5 changes: 2 additions & 3 deletions distribution/src/config/log4j2.properties
Original file line number Diff line number Diff line change
Expand Up @@ -67,7 +67,6 @@ appender.deprecation_rolling.name = deprecation_rolling
appender.deprecation_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation.json
appender.deprecation_rolling.layout.type = ESJsonLayout
appender.deprecation_rolling.layout.type_name = deprecation
appender.deprecation_rolling.layout.esmessagefields=x-opaque-id

appender.deprecation_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation-%i.json.gz
appender.deprecation_rolling.policies.type = Policies
Expand Down Expand Up @@ -104,7 +103,7 @@ appender.index_search_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:f
.cluster_name}_index_search_slowlog.json
appender.index_search_slowlog_rolling.layout.type = ESJsonLayout
appender.index_search_slowlog_rolling.layout.type_name = index_search_slowlog
appender.index_search_slowlog_rolling.layout.esmessagefields=message,took,took_millis,total_hits,stats,search_type,total_shards,source,id
appender.index_search_slowlog_rolling.layout.overrideFields=message

appender.index_search_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs\
.cluster_name}_index_search_slowlog-%i.json.gz
Expand Down Expand Up @@ -143,7 +142,7 @@ appender.index_indexing_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys
_index_indexing_slowlog.json
appender.index_indexing_slowlog_rolling.layout.type = ESJsonLayout
appender.index_indexing_slowlog_rolling.layout.type_name = index_indexing_slowlog
appender.index_indexing_slowlog_rolling.layout.esmessagefields=message,took,took_millis,doc_type,id,routing,source
appender.index_indexing_slowlog_rolling.layout.overrideFields=message

appender.index_indexing_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}\
_index_indexing_slowlog-%i.json.gz
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -50,38 +50,18 @@ public void testLayout() {
"\"node.name\": \"%node_name\", " +
"\"message\": \"%notEmpty{%enc{%marker}{JSON} }%enc{%.-10000m}{JSON}\"" +
"%notEmpty{, %node_and_cluster_id }" +
"%exceptionAsJson }" + System.lineSeparator()));
}

public void testLayoutWithAdditionalFields() {
ESJsonLayout server = ESJsonLayout.newBuilder()
.setType("server")
.setESMessageFields("x-opaque-id,someOtherField")
.build();
String conversionPattern = server.getPatternLayout().getConversionPattern();

assertThat(conversionPattern, Matchers.equalTo(
"{" +
"\"type\": \"server\", " +
"\"timestamp\": \"%d{yyyy-MM-dd'T'HH:mm:ss,SSSZZ}\", " +
"\"level\": \"%p\", " +
"\"component\": \"%c{1.}\", " +
"\"cluster.name\": \"${sys:es.logs.cluster_name}\", " +
"\"node.name\": \"%node_name\", " +
"\"message\": \"%notEmpty{%enc{%marker}{JSON} }%enc{%.-10000m}{JSON}\"" +
"%notEmpty{, \"x-opaque-id\": \"%ESMessageField{x-opaque-id}\"}" +
"%notEmpty{, \"someOtherField\": \"%ESMessageField{someOtherField}\"}" +
"%notEmpty{, %node_and_cluster_id }" +
"%notEmpty{, %CustomMapFields{} }" +
"%exceptionAsJson }" + System.lineSeparator()));
}

public void testLayoutWithAdditionalFieldOverride() {
ESJsonLayout server = ESJsonLayout.newBuilder()
.setType("server")
.setESMessageFields("message")
.setOverrideFields("message")
.build();
String conversionPattern = server.getPatternLayout().getConversionPattern();

//message field is removed as is expected to be provided by a field from a message
assertThat(conversionPattern, Matchers.equalTo(
"{" +
"\"type\": \"server\", " +
Expand All @@ -90,8 +70,8 @@ public void testLayoutWithAdditionalFieldOverride() {
"\"component\": \"%c{1.}\", " +
"\"cluster.name\": \"${sys:es.logs.cluster_name}\", " +
"\"node.name\": \"%node_name\"" +
"%notEmpty{, \"message\": \"%ESMessageField{message}\"}" +
"%notEmpty{, %node_and_cluster_id }" +
"%notEmpty{, %CustomMapFields{message} }" +
"%exceptionAsJson }" + System.lineSeparator()));
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -38,6 +38,7 @@
import org.junit.BeforeClass;

import java.io.IOException;
import java.nio.file.Files;
import java.nio.file.Path;
import java.util.List;
import java.util.Map;
Expand Down Expand Up @@ -78,8 +79,8 @@ public void tearDown() throws Exception {
super.tearDown();
}
public void testDeprecatedMessage() throws IOException {
final Logger testLogger = LogManager.getLogger("test");
testLogger.info(new DeprecatedMessage("deprecated message1", "someId"));
final Logger testLogger = LogManager.getLogger("deprecation.test");
testLogger.info(DeprecatedMessage.of("someId","deprecated message1"));

final Path path = PathUtils.get(System.getProperty("es.logs.base_path"),
System.getProperty("es.logs.cluster_name") + "_deprecated.json");
Expand All @@ -91,7 +92,7 @@ public void testDeprecatedMessage() throws IOException {
allOf(
hasEntry("type", "deprecation"),
hasEntry("level", "INFO"),
hasEntry("component", "test"),
hasEntry("component", "d.test"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("node.name", "sample-name"),
hasEntry("message", "deprecated message1"),
Expand All @@ -101,12 +102,126 @@ public void testDeprecatedMessage() throws IOException {
}
}

public void testMessageOverrideWithNoValue() throws IOException {
//message field is meant to be overriden (see custom.test config), but is not provided.
//Expected is that it will be emptied
final Logger testLogger = LogManager.getLogger("custom.test");

testLogger.info(new ESLogMessage("some message"));

final Path path = PathUtils.get(System.getProperty("es.logs.base_path"),
System.getProperty("es.logs.cluster_name") + "_custom.json");
try (Stream<Map<String, String>> stream = JsonLogsStream.mapStreamFrom(path)) {
List<Map<String, String>> jsonLogs = stream
.collect(Collectors.toList());

assertThat(jsonLogs, contains(
allOf(
hasEntry("type", "custom"),
hasEntry("level", "INFO"),
hasEntry("component", "c.test"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("node.name", "sample-name"))
)
);
}
}
public void testBuildingMessage() throws IOException {
alpar-t marked this conversation as resolved.
Show resolved Hide resolved

public void testDeprecatedMessageWithoutXOpaqueId() throws IOException {
final Logger testLogger = LogManager.getLogger("test");
testLogger.info(new DeprecatedMessage("deprecated message1", "someId"));
testLogger.info(new DeprecatedMessage("deprecated message2", ""));
testLogger.info(new DeprecatedMessage("deprecated message3", null));

testLogger.info(new ESLogMessage("some message {} {}", "value0")
.argAndField("key1","value1")
.field("key2","value2"));

final Path path = PathUtils.get(System.getProperty("es.logs.base_path"),
System.getProperty("es.logs.cluster_name") + ".json");
try (Stream<Map<String, String>> stream = JsonLogsStream.mapStreamFrom(path)) {
List<Map<String, String>> jsonLogs = stream
.collect(Collectors.toList());

assertThat(jsonLogs, contains(
allOf(
hasEntry("type", "file"),
hasEntry("level", "INFO"),
hasEntry("component", "test"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("node.name", "sample-name"),
hasEntry("message", "some message value0 value1"),
hasEntry("key1", "value1"),
hasEntry("key2", "value2"))
)
);
}
}

public void testMessageOverride() throws IOException {

final Logger testLogger = LogManager.getLogger("custom.test");
testLogger.info(new ESLogMessage("some message")
.with("message","overriden"));


final Path path = PathUtils.get(System.getProperty("es.logs.base_path"),
System.getProperty("es.logs.cluster_name") + "_custom.json");
try (Stream<Map<String, String>> stream = JsonLogsStream.mapStreamFrom(path)) {
List<Map<String, String>> jsonLogs = stream
.collect(Collectors.toList());

assertThat(jsonLogs, contains(
allOf(
hasEntry("type", "custom"),
hasEntry("level", "INFO"),
hasEntry("component", "c.test"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("node.name", "sample-name"),
hasEntry("message", "overriden"))
)
);
}

final Path plaintextPath = PathUtils.get(System.getProperty("es.logs.base_path"),
System.getProperty("es.logs.cluster_name") + "_plaintext.json");
List<String> lines = Files.readAllLines(plaintextPath);
assertThat(lines, contains("some message"));


}

public void testCustomMessageWithMultipleFields() throws IOException {
// if a field is defined to be overriden, it has to always be overriden in that appender.
final Logger testLogger = LogManager.getLogger("test");
testLogger.info(new ESLogMessage("some message")
.with("field1","value1")
.with("field2","value2"));

final Path path = PathUtils.get(System.getProperty("es.logs.base_path"),
System.getProperty("es.logs.cluster_name") + ".json");
try (Stream<Map<String, String>> stream = JsonLogsStream.mapStreamFrom(path)) {
List<Map<String, String>> jsonLogs = stream
.collect(Collectors.toList());

assertThat(jsonLogs, contains(
allOf(
hasEntry("type", "file"),
hasEntry("level", "INFO"),
hasEntry("component", "test"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("node.name", "sample-name"),
hasEntry("field1", "value1"),
hasEntry("field2", "value2"),
hasEntry("message", "some message"))
)
);
}
}


public void testDeprecatedMessageWithoutXOpaqueId() throws IOException {
final Logger testLogger = LogManager.getLogger("deprecation.test");
testLogger.info( DeprecatedMessage.of("someId","deprecated message1"));
testLogger.info( DeprecatedMessage.of("","deprecated message2"));
testLogger.info( DeprecatedMessage.of(null,"deprecated message3"));
testLogger.info("deprecated message4");

final Path path = PathUtils.get(System.getProperty("es.logs.base_path"),
Expand All @@ -119,15 +234,15 @@ public void testDeprecatedMessageWithoutXOpaqueId() throws IOException {
allOf(
hasEntry("type", "deprecation"),
hasEntry("level", "INFO"),
hasEntry("component", "test"),
hasEntry("component", "d.test"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("node.name", "sample-name"),
hasEntry("message", "deprecated message1"),
hasEntry("x-opaque-id", "someId")),
allOf(
hasEntry("type", "deprecation"),
hasEntry("level", "INFO"),
hasEntry("component", "test"),
hasEntry("component", "d.test"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("node.name", "sample-name"),
hasEntry("message", "deprecated message2"),
Expand All @@ -136,7 +251,7 @@ public void testDeprecatedMessageWithoutXOpaqueId() throws IOException {
allOf(
hasEntry("type", "deprecation"),
hasEntry("level", "INFO"),
hasEntry("component", "test"),
hasEntry("component", "d.test"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("node.name", "sample-name"),
hasEntry("message", "deprecated message3"),
Expand All @@ -145,7 +260,7 @@ public void testDeprecatedMessageWithoutXOpaqueId() throws IOException {
allOf(
hasEntry("type", "deprecation"),
hasEntry("level", "INFO"),
hasEntry("component", "test"),
hasEntry("component", "d.test"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("node.name", "sample-name"),
hasEntry("message", "deprecated message4"),
Expand Down Expand Up @@ -179,19 +294,19 @@ public void testJsonLayout() throws IOException {
}

public void testPrefixLoggerInJson() throws IOException {
Logger shardIdLogger = Loggers.getLogger("shardIdLogger", ShardId.fromString("[indexName][123]"));
Logger shardIdLogger = Loggers.getLogger("prefix.shardIdLogger", ShardId.fromString("[indexName][123]"));
shardIdLogger.info("This is an info message with a shardId");

Logger prefixLogger = new PrefixLogger(LogManager.getLogger("prefixLogger"), "PREFIX");
Logger prefixLogger = new PrefixLogger(LogManager.getLogger("prefix.prefixLogger"), "PREFIX");
prefixLogger.info("This is an info message with a prefix");

final Path path = clusterLogsPath();
try (Stream<JsonLogLine> stream = JsonLogsStream.from(path)) {
List<JsonLogLine> jsonLogs = collectLines(stream);
assertThat(jsonLogs, contains(
logLine("file", Level.INFO, "sample-name", "shardIdLogger",
logLine("file", Level.INFO, "sample-name", "p.shardIdLogger",
"[indexName][123] This is an info message with a shardId"),
logLine("file", Level.INFO, "sample-name", "prefixLogger", "PREFIX This is an info message with a prefix")
logLine("file", Level.INFO, "sample-name", "p.prefixLogger", "PREFIX This is an info message with a prefix")
));
}
}
Expand Down Expand Up @@ -351,12 +466,11 @@ public void testDuplicateLogMessages() throws IOException {

private List<JsonLogLine> collectLines(Stream<JsonLogLine> stream) {
return stream
.skip(1)//skip the first line from super class
.collect(Collectors.toList());
}

private Path clusterLogsPath() {
return PathUtils.get(System.getProperty("es.logs.base_path"), System.getProperty("es.logs.cluster_name") + ".log");
return PathUtils.get(System.getProperty("es.logs.base_path"), System.getProperty("es.logs.cluster_name") + ".json");
}

private void setupLogging(final String config) throws IOException, UserException {
Expand Down
Loading