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.

Sign up for GitHub

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

Refactor ESLogMessage to not define fields upfront #46702

Show file tree
Hide file tree
Changes from 8 commits
Commits
Show all changes
17 commits
Select commit Hold shift + click to select a range
cb24964
refactor ESLogMessage and overriding fields
pgomulka Sep 13, 2019
6b450a9
rename esmessagefields to overrideFields
pgomulka Sep 13, 2019
b23ffb1
javadoc
pgomulka Sep 13, 2019
5605955
simplify custom message class creation
pgomulka Sep 27, 2019
74cb563
line length
pgomulka Sep 27, 2019
ad55b7b
Merge branch 'master' into feature/logging-parametrised
elasticmachine Sep 27, 2019
ba1bf6f
small cleanup and rename of ESJsonField
pgomulka Sep 30, 2019
d9bfd89
Merge branch 'feature/logging-parametrised' of github.com:pgomulka/el…
pgomulka Sep 30, 2019
bf0d670
working with builder
pgomulka Oct 2, 2019
ae1bc99
parametrized map - basing on ecs
pgomulka Oct 2, 2019
9c38db3
builder
pgomulka Oct 4, 2019
9f307c8
refactoring and cleanup
pgomulka Oct 4, 2019
2025181
cleanup
pgomulka Oct 4, 2019
747c220
Merge branch 'master' into feature/logging-parametrised
elasticmachine Oct 7, 2019
40cd0ef
logger checker
pgomulka Oct 8, 2019
7bf85c8
Merge branch 'feature/logging-parametrised' of github.com:pgomulka/el…
pgomulka Oct 8, 2019
c4d7cd4
Merge branch 'master' into feature/logging-parametrised
pgomulka Oct 8, 2019
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
5 changes: 2 additions & 3 deletions distribution/docker/docker-build-context/src/docker/config/log4j2.properties
View file
Open in desktop
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
View file
Open in desktop
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
28 changes: 4 additions & 24 deletions qa/logging-config/src/test/java/org/elasticsearch/common/logging/ESJsonLayoutTests.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -50,35 +50,14 @@ 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();

Expand All @@ -90,8 +69,9 @@ public void testLayoutWithAdditionalFieldOverride() {
"\"component\": \"%c{1.}\", " +
"\"cluster.name\": \"${sys:es.logs.cluster_name}\", " +
"\"node.name\": \"%node_name\"" +
"%notEmpty{, \"message\": \"%ESMessageField{message}\"}" +
"%notEmpty{, \"message\": \"%OverrideField{message}\"}" +
"%notEmpty{, %node_and_cluster_id }" +
"%notEmpty{, %CustomMapFields{message} }" +
"%exceptionAsJson }" + System.lineSeparator()));
}
}
101 changes: 93 additions & 8 deletions qa/logging-config/src/test/java/org/elasticsearch/common/logging/JsonLoggerTests.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -78,7 +78,7 @@ public void tearDown() throws Exception {
super.tearDown();
}
public void testDeprecatedMessage() throws IOException {
final Logger testLogger = LogManager.getLogger("test");
final Logger testLogger = LogManager.getLogger("deprecation.test");
testLogger.info(new DeprecatedMessage("deprecated message1", "someId"));

final Path path = PathUtils.get(System.getProperty("es.logs.base_path"),
Expand All @@ -91,7 +91,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,9 +101,94 @@ 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(ESLogMessage.message("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 testMessageOverride() throws IOException {

final Logger testLogger = LogManager.getLogger("custom.test");

testLogger.info(ESLogMessage.message("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"))
)
);
}
}

public void testCustomMessageWithMultipleFields() throws IOException {
// if a field is defined to be overriden, it has to always be overriden in that appender.
class CustomMessage extends ESLogMessage{
CustomMessage() {
super(Map.of("field1","value1","field2","value2", "message", "some message"), "some message");
}
}

final Logger testLogger = LogManager.getLogger("custom.test");
testLogger.info(new CustomMessage());


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("field1", "value1"),
hasEntry("field2", "value2"),
hasEntry("message", "some message"))
)
);
}
}


public void testDeprecatedMessageWithoutXOpaqueId() throws IOException {
final Logger testLogger = LogManager.getLogger("test");
final Logger testLogger = LogManager.getLogger("deprecation.test");
testLogger.info(new DeprecatedMessage("deprecated message1", "someId"));
testLogger.info(new DeprecatedMessage("deprecated message2", ""));
testLogger.info(new DeprecatedMessage("deprecated message3", null));
Expand All @@ -119,15 +204,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 +221,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 +230,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 @@ -356,7 +441,7 @@ private List<JsonLogLine> collectLines(Stream<JsonLogLine> stream) {
}

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
38 changes: 23 additions & 15 deletions ...-config/src/test/resources/org/elasticsearch/common/logging/json_layout/log4j2.properties
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,7 @@ appender.console.layout.type_name = console

appender.file.type = File
appender.file.name = file
appender.file.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}.log
appender.file.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}.json
appender.file.layout.type = ESJsonLayout
appender.file.layout.type_name = file

Expand All @@ -14,38 +14,46 @@ appender.deprecated.name = deprecated
appender.deprecated.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecated.json
appender.deprecated.layout.type = ESJsonLayout
appender.deprecated.layout.type_name = deprecation
appender.deprecated.layout.esmessagefields = x-opaque-id

appender.deprecatedconsole.type = Console
appender.deprecatedconsole.name = deprecatedconsole
appender.deprecatedconsole.layout.type = ESJsonLayout
appender.deprecatedconsole.layout.type_name = deprecation
appender.deprecatedconsole.layout.esmessagefields = x-opaque-id

appender.index_search_slowlog_rolling.type = File
appender.index_search_slowlog_rolling.name = index_search_slowlog_rolling
appender.index_search_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs\
.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,types,stats,search_type,total_shards,source,id

appender.customconsole.type = Console
appender.customconsole.name = customconsole
appender.customconsole.layout.type = ESJsonLayout
appender.customconsole.layout.type_name = custom
appender.customconsole.layout.overrideFields = message

appender.custom.type = File
appender.custom.name = custom
appender.custom.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs\
.cluster_name}_custom.json
appender.custom.layout.type = ESJsonLayout
appender.custom.layout.type_name = custom
appender.custom.layout.overrideFields = message

rootLogger.level = info
rootLogger.appenderRef.console.ref = console
rootLogger.appenderRef.file.ref = file

logger.deprecation.name = deprecation.test
logger.deprecation.level = warn
logger.deprecation.appenderRef.console.ref = console
logger.deprecation.appenderRef.file.ref = file
logger.deprecation.level = trace
logger.deprecation.appenderRef.deprecation_rolling.ref = deprecated
logger.deprecation.appenderRef.deprecatedconsole.ref = deprecatedconsole
logger.deprecation.additivity = false


logger.custom.name = custom.test
logger.custom.level = trace
logger.custom.appenderRef.console.ref = custom
logger.custom.appenderRef.file.ref = customconsole
logger.custom.additivity = false

logger.test.name = test
logger.test.level = trace
logger.test.appenderRef.console.ref = console
logger.test.appenderRef.file.ref = file
logger.test.appenderRef.deprecated.ref = deprecated
logger.test.appenderRef.deprecatedconsole.ref = deprecatedconsole
logger.test.additivity = false
7 changes: 6 additions & 1 deletion server/src/main/java/org/elasticsearch/cluster/routing/allocation/AllocationService.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -40,6 +40,7 @@
import org.elasticsearch.cluster.routing.allocation.command.AllocationCommands;
import org.elasticsearch.cluster.routing.allocation.decider.AllocationDeciders;
import org.elasticsearch.common.collect.ImmutableOpenMap;
import org.elasticsearch.common.logging.ESLogMessage;
import org.elasticsearch.gateway.GatewayAllocator;

import java.util.ArrayList;
Expand Down Expand Up @@ -378,7 +379,11 @@ private void logClusterHealthStateChange(ClusterStateHealth previousStateHealth,
ClusterHealthStatus previousHealth = previousStateHealth.getStatus();
ClusterHealthStatus currentHealth = newStateHealth.getStatus();
if (!previousHealth.equals(currentHealth)) {
logger.info("Cluster health status changed from [{}] to [{}] (reason: [{}]).", previousHealth, currentHealth, reason);
logger.info(ESLogMessage.message("Cluster health status changed from [{}] to [{}] (reason: [{}]).",
previousHealth, currentHealth, reason)
.with("previous.health", previousHealth)
.with("current.health", currentHealth)
.with("reason", reason));
}
}

Expand Down
Loading