Skip to content

Commit 979c33b

Browse files
pgomulkapgomulka
authored
Make Elasticsearch JSON logs ECS compliant (#47105)
Updating log4j2 configuration to use `EcsLayout` for our JSON logs https://github.com/elastic/ecs-logging-java instead of previously used `ESJsonLayout` ESJsonLayout is still supported, but will be marked as deprecated. Deprecation, Indexing and Search slow logs are in ECS JSON format only. Plaintext is no longer backwards compatible and will result in different output. Server logs are in both plaintext and ECS JSON format. relates #49087
1 parent 6fcb51d commit 979c33b

File tree

42 files changed

+6581
-413
lines changed

Some content is hidden

Large Commits have some content hidden by default. Use the searchbox below for content that may be hidden.

42 files changed

+6581
-413
lines changed

‎buildSrc/version.properties

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,7 @@ supercsv = 2.4.0
1616
# when updating log4j, please update also docs/java-api/index.asciidoc
1717
log4j = 2.11.1
1818
slf4j = 1.6.2
19+
ecsLogging = 0.1.3
1920

2021
# when updating the JNA version, also update the version in buildSrc/build.gradle
2122
jna = 4.5.1

‎distribution/docker/src/docker/config/log4j2.properties

Lines changed: 4 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -6,15 +6,15 @@ logger.action.level = debug
66

77
appender.rolling.type = Console
88
appender.rolling.name = rolling
9-
appender.rolling.layout.type = ESJsonLayout
9+
appender.rolling.layout.type = ECSJsonLayout
1010
appender.rolling.layout.type_name = server
1111

1212
rootLogger.level = info
1313
rootLogger.appenderRef.rolling.ref = rolling
1414

1515
appender.deprecation_rolling.type = Console
1616
appender.deprecation_rolling.name = deprecation_rolling
17-
appender.deprecation_rolling.layout.type = ESJsonLayout
17+
appender.deprecation_rolling.layout.type = ECSJsonLayout
1818
appender.deprecation_rolling.layout.type_name = deprecation
1919

2020
logger.deprecation.name = org.elasticsearch.deprecation
@@ -24,9 +24,8 @@ logger.deprecation.additivity = false
2424

2525
appender.index_search_slowlog_rolling.type = Console
2626
appender.index_search_slowlog_rolling.name = index_search_slowlog_rolling
27-
appender.index_search_slowlog_rolling.layout.type = ESJsonLayout
27+
appender.index_search_slowlog_rolling.layout.type = ECSJsonLayout
2828
appender.index_search_slowlog_rolling.layout.type_name = index_search_slowlog
29-
appender.index_search_slowlog_rolling.layout.overrideFields=message
3029

3130
logger.index_search_slowlog_rolling.name = index.search.slowlog
3231
logger.index_search_slowlog_rolling.level = trace
@@ -35,9 +34,8 @@ logger.index_search_slowlog_rolling.additivity = false
3534

3635
appender.index_indexing_slowlog_rolling.type = Console
3736
appender.index_indexing_slowlog_rolling.name = index_indexing_slowlog_rolling
38-
appender.index_indexing_slowlog_rolling.layout.type = ESJsonLayout
37+
appender.index_indexing_slowlog_rolling.layout.type = ECSJsonLayout
3938
appender.index_indexing_slowlog_rolling.layout.type_name = index_indexing_slowlog
40-
appender.index_indexing_slowlog_rolling.layout.overrideFields=message
4139

4240
logger.index_indexing_slowlog.name = index.indexing.slowlog.index
4341
logger.index_indexing_slowlog.level = trace

‎distribution/docker/src/docker/config/oss/log4j2.properties

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -6,15 +6,15 @@ logger.action.level = debug
66

77
appender.rolling.type = Console
88
appender.rolling.name = rolling
9-
appender.rolling.layout.type = ESJsonLayout
9+
appender.rolling.layout.type = ECSJsonLayout
1010
appender.rolling.layout.type_name = server
1111

1212
rootLogger.level = info
1313
rootLogger.appenderRef.rolling.ref = rolling
1414

1515
appender.deprecation_rolling.type = Console
1616
appender.deprecation_rolling.name = deprecation_rolling
17-
appender.deprecation_rolling.layout.type = ESJsonLayout
17+
appender.deprecation_rolling.layout.type = ECSJsonLayout
1818
appender.deprecation_rolling.layout.type_name = deprecation
1919

2020
logger.deprecation.name = org.elasticsearch.deprecation
@@ -24,7 +24,7 @@ logger.deprecation.additivity = false
2424

2525
appender.index_search_slowlog_rolling.type = Console
2626
appender.index_search_slowlog_rolling.name = index_search_slowlog_rolling
27-
appender.index_search_slowlog_rolling.layout.type = ESJsonLayout
27+
appender.index_search_slowlog_rolling.layout.type = ECSJsonLayout
2828
appender.index_search_slowlog_rolling.layout.type_name = index_search_slowlog
2929

3030
logger.index_search_slowlog_rolling.name = index.search.slowlog
@@ -34,7 +34,7 @@ logger.index_search_slowlog_rolling.additivity = false
3434

3535
appender.index_indexing_slowlog_rolling.type = Console
3636
appender.index_indexing_slowlog_rolling.name = index_indexing_slowlog_rolling
37-
appender.index_indexing_slowlog_rolling.layout.type = ESJsonLayout
37+
appender.index_indexing_slowlog_rolling.layout.type = ECSJsonLayout
3838
appender.index_indexing_slowlog_rolling.layout.type_name = index_indexing_slowlog
3939

4040
logger.index_indexing_slowlog.name = index.indexing.slowlog.index

‎distribution/src/config/log4j2.properties

Lines changed: 8 additions & 55 deletions
Original file line numberDiff line numberDiff line change
@@ -9,7 +9,7 @@ appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%ma
99
appender.rolling.type = RollingFile
1010
appender.rolling.name = rolling
1111
appender.rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_server.json
12-
appender.rolling.layout.type = ESJsonLayout
12+
appender.rolling.layout.type = ECSJsonLayout
1313
appender.rolling.layout.type_name = server
1414

1515
appender.rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}-%d{yyyy-MM-dd}-%i.json.gz
@@ -61,7 +61,7 @@ rootLogger.appenderRef.rolling_old.ref = rolling_old
6161
appender.deprecation_rolling.type = RollingFile
6262
appender.deprecation_rolling.name = deprecation_rolling
6363
appender.deprecation_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation.json
64-
appender.deprecation_rolling.layout.type = ESJsonLayout
64+
appender.deprecation_rolling.layout.type = ECSJsonLayout
6565
appender.deprecation_rolling.layout.type_name = deprecation
6666

6767
appender.deprecation_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation-%i.json.gz
@@ -71,35 +71,19 @@ appender.deprecation_rolling.policies.size.size = 1GB
7171
appender.deprecation_rolling.strategy.type = DefaultRolloverStrategy
7272
appender.deprecation_rolling.strategy.max = 4
7373
#################################################
74-
######## Deprecation - old style pattern #######
75-
appender.deprecation_rolling_old.type = RollingFile
76-
appender.deprecation_rolling_old.name = deprecation_rolling_old
77-
appender.deprecation_rolling_old.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation.log
78-
appender.deprecation_rolling_old.layout.type = PatternLayout
79-
appender.deprecation_rolling_old.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %m%n
80-
81-
appender.deprecation_rolling_old.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}\
82-
_deprecation-%i.log.gz
83-
appender.deprecation_rolling_old.policies.type = Policies
84-
appender.deprecation_rolling_old.policies.size.type = SizeBasedTriggeringPolicy
85-
appender.deprecation_rolling_old.policies.size.size = 1GB
86-
appender.deprecation_rolling_old.strategy.type = DefaultRolloverStrategy
87-
appender.deprecation_rolling_old.strategy.max = 4
88-
#################################################
74+
8975
logger.deprecation.name = org.elasticsearch.deprecation
9076
logger.deprecation.level = warn
9177
logger.deprecation.appenderRef.deprecation_rolling.ref = deprecation_rolling
92-
logger.deprecation.appenderRef.deprecation_rolling_old.ref = deprecation_rolling_old
9378
logger.deprecation.additivity = false
9479

9580
######## Search slowlog JSON ####################
9681
appender.index_search_slowlog_rolling.type = RollingFile
9782
appender.index_search_slowlog_rolling.name = index_search_slowlog_rolling
9883
appender.index_search_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs\
9984
.cluster_name}_index_search_slowlog.json
100-
appender.index_search_slowlog_rolling.layout.type = ESJsonLayout
85+
appender.index_search_slowlog_rolling.layout.type = ECSJsonLayout
10186
appender.index_search_slowlog_rolling.layout.type_name = index_search_slowlog
102-
appender.index_search_slowlog_rolling.layout.overrideFields=message
10387

10488
appender.index_search_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs\
10589
.cluster_name}_index_search_slowlog-%i.json.gz
@@ -109,36 +93,21 @@ appender.index_search_slowlog_rolling.policies.size.size = 1GB
10993
appender.index_search_slowlog_rolling.strategy.type = DefaultRolloverStrategy
11094
appender.index_search_slowlog_rolling.strategy.max = 4
11195
#################################################
112-
######## Search slowlog - old style pattern ####
113-
appender.index_search_slowlog_rolling_old.type = RollingFile
114-
appender.index_search_slowlog_rolling_old.name = index_search_slowlog_rolling_old
115-
appender.index_search_slowlog_rolling_old.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}\
116-
_index_search_slowlog.log
117-
appender.index_search_slowlog_rolling_old.layout.type = PatternLayout
118-
appender.index_search_slowlog_rolling_old.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %m%n
119-
120-
appender.index_search_slowlog_rolling_old.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}\
121-
_index_search_slowlog-%i.log.gz
122-
appender.index_search_slowlog_rolling_old.policies.type = Policies
123-
appender.index_search_slowlog_rolling_old.policies.size.type = SizeBasedTriggeringPolicy
124-
appender.index_search_slowlog_rolling_old.policies.size.size = 1GB
125-
appender.index_search_slowlog_rolling_old.strategy.type = DefaultRolloverStrategy
126-
appender.index_search_slowlog_rolling_old.strategy.max = 4
96+
12797
#################################################
12898
logger.index_search_slowlog_rolling.name = index.search.slowlog
12999
logger.index_search_slowlog_rolling.level = trace
130100
logger.index_search_slowlog_rolling.appenderRef.index_search_slowlog_rolling.ref = index_search_slowlog_rolling
131-
logger.index_search_slowlog_rolling.appenderRef.index_search_slowlog_rolling_old.ref = index_search_slowlog_rolling_old
132101
logger.index_search_slowlog_rolling.additivity = false
133102

134103
######## Indexing slowlog JSON ##################
135104
appender.index_indexing_slowlog_rolling.type = RollingFile
136105
appender.index_indexing_slowlog_rolling.name = index_indexing_slowlog_rolling
137106
appender.index_indexing_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}\
138107
_index_indexing_slowlog.json
139-
appender.index_indexing_slowlog_rolling.layout.type = ESJsonLayout
108+
appender.index_indexing_slowlog_rolling.layout.type = ECSJsonLayout
140109
appender.index_indexing_slowlog_rolling.layout.type_name = index_indexing_slowlog
141-
appender.index_indexing_slowlog_rolling.layout.overrideFields=message
110+
142111

143112
appender.index_indexing_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}\
144113
_index_indexing_slowlog-%i.json.gz
@@ -148,25 +117,9 @@ appender.index_indexing_slowlog_rolling.policies.size.size = 1GB
148117
appender.index_indexing_slowlog_rolling.strategy.type = DefaultRolloverStrategy
149118
appender.index_indexing_slowlog_rolling.strategy.max = 4
150119
#################################################
151-
######## Indexing slowlog - old style pattern ##
152-
appender.index_indexing_slowlog_rolling_old.type = RollingFile
153-
appender.index_indexing_slowlog_rolling_old.name = index_indexing_slowlog_rolling_old
154-
appender.index_indexing_slowlog_rolling_old.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}\
155-
_index_indexing_slowlog.log
156-
appender.index_indexing_slowlog_rolling_old.layout.type = PatternLayout
157-
appender.index_indexing_slowlog_rolling_old.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %m%n
158-
159-
appender.index_indexing_slowlog_rolling_old.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}\
160-
_index_indexing_slowlog-%i.log.gz
161-
appender.index_indexing_slowlog_rolling_old.policies.type = Policies
162-
appender.index_indexing_slowlog_rolling_old.policies.size.type = SizeBasedTriggeringPolicy
163-
appender.index_indexing_slowlog_rolling_old.policies.size.size = 1GB
164-
appender.index_indexing_slowlog_rolling_old.strategy.type = DefaultRolloverStrategy
165-
appender.index_indexing_slowlog_rolling_old.strategy.max = 4
166-
#################################################
120+
167121

168122
logger.index_indexing_slowlog.name = index.indexing.slowlog.index
169123
logger.index_indexing_slowlog.level = trace
170124
logger.index_indexing_slowlog.appenderRef.index_indexing_slowlog_rolling.ref = index_indexing_slowlog_rolling
171-
logger.index_indexing_slowlog.appenderRef.index_indexing_slowlog_rolling_old.ref = index_indexing_slowlog_rolling_old
172125
logger.index_indexing_slowlog.additivity = false

‎qa/die-with-dignity/src/main/java/org/elasticsearch/DieWithDignityPlugin.java

Lines changed: 8 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -42,13 +42,14 @@ public DieWithDignityPlugin() {
4242

4343
@Override
4444
public List<RestHandler> getRestHandlers(
45-
final Settings settings,
46-
final RestController restController,
47-
final ClusterSettings clusterSettings,
48-
final IndexScopedSettings indexScopedSettings,
49-
final SettingsFilter settingsFilter,
50-
final IndexNameExpressionResolver indexNameExpressionResolver,
51-
final Supplier<DiscoveryNodes> nodesInCluster) {
45+
final Settings settings,
46+
final RestController restController,
47+
final ClusterSettings clusterSettings,
48+
final IndexScopedSettings indexScopedSettings,
49+
final SettingsFilter settingsFilter,
50+
final IndexNameExpressionResolver indexNameExpressionResolver,
51+
final Supplier<DiscoveryNodes> nodesInCluster
52+
) {
5253
return Collections.singletonList(new RestDieWithDignityAction());
5354
}
5455

‎qa/die-with-dignity/src/test/java/org/elasticsearch/qa/die_with_dignity/DieWithDignityIT.java

Lines changed: 22 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -39,18 +39,14 @@
3939
public class DieWithDignityIT extends ESRestTestCase {
4040

4141
public void testDieWithDignity() throws Exception {
42-
expectThrows(
43-
IOException.class,
44-
() -> client().performRequest(new Request("GET", "/_die_with_dignity"))
45-
);
42+
expectThrows(IOException.class, () -> client().performRequest(new Request("GET", "/_die_with_dignity")));
4643

4744
// the Elasticsearch process should die and disappear from the output of jps
4845
assertBusy(() -> {
4946
final String jpsPath = PathUtils.get(System.getProperty("runtime.java.home"), "bin/jps").toString();
5047
final Process process = new ProcessBuilder().command(jpsPath, "-v").start();
5148

52-
try (InputStream is = process.getInputStream();
53-
BufferedReader in = new BufferedReader(new InputStreamReader(is, "UTF-8"))) {
49+
try (InputStream is = process.getInputStream(); BufferedReader in = new BufferedReader(new InputStreamReader(is, "UTF-8"))) {
5450
String line;
5551
while ((line = in.readLine()) != null) {
5652
assertThat(line, line, not(containsString("-Ddie.with.dignity.test")));
@@ -60,21 +56,24 @@ public void testDieWithDignity() throws Exception {
6056

6157
// parse the logs and ensure that Elasticsearch died with the expected cause
6258
final List<String> lines = Files.readAllLines(PathUtils.get(System.getProperty("log")));
63-
6459
final Iterator<String> it = lines.iterator();
6560

6661
boolean fatalError = false;
6762
boolean fatalErrorInThreadExiting = false;
6863
try {
6964
while (it.hasNext() && (fatalError == false || fatalErrorInThreadExiting == false)) {
7065
final String line = it.next();
71-
if (line.matches(".*ERROR.*o\\.e\\.ExceptionsHelper.*integTest-0.*fatal error.*")) {
66+
if (containsAll(line, ".*ERROR.*", ".*ExceptionsHelper.*", ".*integTest-0.*", ".*fatal error.*")) {
7267
fatalError = true;
73-
} else if (line.matches(".*ERROR.*o\\.e\\.b\\.ElasticsearchUncaughtExceptionHandler.*integTest-0.*"
74-
+ "fatal error in thread \\[Thread-\\d+\\], exiting.*")) {
68+
} else if (containsAll(
69+
line,
70+
".*ERROR.*",
71+
".*ElasticsearchUncaughtExceptionHandler.*",
72+
".*integTest-0.*",
73+
".*fatal error in thread \\[Thread-\\d+\\], exiting.*",
74+
".*java.lang.OutOfMemoryError: die with dignity.*"
75+
)) {
7576
fatalErrorInThreadExiting = true;
76-
assertTrue(it.hasNext());
77-
assertThat(it.next(), containsString("java.lang.OutOfMemoryError: die with dignity"));
7877
}
7978
}
8079

@@ -88,6 +87,15 @@ public void testDieWithDignity() throws Exception {
8887
}
8988
}
9089

90+
private boolean containsAll(String line, String... subStrings) {
91+
for (String subString : subStrings) {
92+
if (line.matches(subString) == false) {
93+
return false;
94+
}
95+
}
96+
return true;
97+
}
98+
9199
private void debugLogs(Path path) throws IOException {
92100
try (BufferedReader reader = Files.newBufferedReader(path)) {
93101
reader.lines().forEach(line -> logger.info(line));
@@ -102,7 +110,8 @@ protected boolean preserveClusterUponCompletion() {
102110

103111
@Override
104112
protected final Settings restClientSettings() {
105-
return Settings.builder().put(super.restClientSettings())
113+
return Settings.builder()
114+
.put(super.restClientSettings())
106115
// increase the timeout here to 90 seconds to handle long waits for a green
107116
// cluster health. the waits for green need to be longer than a minute to
108117
// account for delayed shards

‎qa/evil-tests/src/test/java/org/elasticsearch/common/logging/EvilLoggerTests.java

Lines changed: 7 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -195,8 +195,14 @@ public void testConcurrentDeprecationLogger() throws IOException, UserException,
195195
"_deprecation.log";
196196
final List<String> deprecationEvents = Files.readAllLines(PathUtils.get(deprecationPath));
197197
// we appended an integer to each log message, use that for sorting
198-
deprecationEvents.sort(Comparator.comparingInt(s -> Integer.parseInt(s.split("message")[1])));
198+
Pattern pattern = Pattern.compile(".*message(\\d+)\"");
199+
deprecationEvents.sort(Comparator.comparingInt(s -> {
200+
Matcher matcher = pattern.matcher(s);
201+
matcher.matches();
202+
return Integer.parseInt(matcher.group(1));
203+
}));
199204
assertThat(deprecationEvents.size(), equalTo(128));
205+
200206
for (int i = 0; i < 128; i++) {
201207
assertLogLine(
202208
deprecationEvents.get(i),

‎qa/logging-config/build.gradle

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -32,7 +32,10 @@ testClusters.integTest {
3232

3333
integTest.runner {
3434
nonInputProperties.systemProperty 'tests.logfile',
35-
"${-> testClusters.integTest.singleNode().getServerLog().absolutePath.replaceAll(".json", ".log")}"
35+
"${-> testClusters.integTest.singleNode().getServerLog().absolutePath.replaceAll("_server.json", ".log")}"
36+
37+
nonInputProperties.systemProperty 'tests.jsonLogfile',
38+
"${-> testClusters.integTest.singleNode().getServerLog()}"
3639
}
3740

3841
test {

0 commit comments

Comments
 (0)