Skip to content

Commit d219a85

Browse files
jasontedorjasontedor
authored
Use LRU set to reduce repeat deprecation messages
This commit adds an LRU set to used to determine if a keyed deprecation message should be written to the deprecation logs, or only added to the response headers on the thread context. Relates elastic#25474
1 parent cac2eec commit d219a85

File tree

7 files changed

+173
-51
lines changed

7 files changed

+173
-51
lines changed

‎core/src/main/java/org/elasticsearch/common/logging/DeprecationLogger.java‎

Lines changed: 31 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -31,8 +31,10 @@
3131
import java.time.format.DateTimeFormatter;
3232
import java.time.format.DateTimeFormatterBuilder;
3333
import java.time.format.SignStyle;
34+
import java.util.Collections;
3435
import java.util.HashMap;
3536
import java.util.Iterator;
37+
import java.util.LinkedHashMap;
3638
import java.util.Locale;
3739
import java.util.Map;
3840
import java.util.Objects;
@@ -118,12 +120,32 @@ public DeprecationLogger(Logger parentLogger) {
118120
}
119121

120122
/**
121-
* Logs a deprecated message.
123+
* Logs a deprecation message, adding a formatted warning message as a response header on the thread context.
122124
*/
123125
public void deprecated(String msg, Object... params) {
124126
deprecated(THREAD_CONTEXT, msg, params);
125127
}
126128

129+
// LRU set of keys used to determine if a deprecation message should be emitted to the deprecation logs
130+
private Set<String> keys = Collections.newSetFromMap(Collections.synchronizedMap(new LinkedHashMap<String, Boolean>() {
131+
@Override
132+
protected boolean removeEldestEntry(final Map.Entry eldest) {
133+
return size() > 128;
134+
}
135+
}));
136+
137+
/**
138+
* Adds a formatted warning message as a response header on the thread context, and logs a deprecation message if the associated key has
139+
* not recently been seen.
140+
*
141+
* @param key the key used to determine if this deprecation should be logged
142+
* @param msg the message to log
143+
* @param params parameters to the message
144+
*/
145+
public void deprecatedAndMaybeLog(final String key, final String msg, final Object... params) {
146+
deprecated(THREAD_CONTEXT, msg, keys.add(key), params);
147+
}
148+
127149
/*
128150
* RFC7234 specifies the warning format as warn-code <space> warn-agent <space> "warn-text" [<space> "warn-date"]. Here, warn-code is a
129151
* three-digit number with various standard warn codes specified. The warn code 299 is apt for our purposes as it represents a
@@ -270,8 +292,12 @@ private static boolean assertWarningValue(final String s, final String warningVa
270292
* @param message The deprecation message.
271293
* @param params The parameters used to fill in the message, if any exist.
272294
*/
273-
@SuppressLoggerChecks(reason = "safely delegates to logger")
274295
void deprecated(final Set<ThreadContext> threadContexts, final String message, final Object... params) {
296+
deprecated(threadContexts, message, true, params);
297+
}
298+
299+
@SuppressLoggerChecks(reason = "safely delegates to logger")
300+
void deprecated(final Set<ThreadContext> threadContexts, final String message, final boolean log, final Object... params) {
275301
final Iterator<ThreadContext> iterator = threadContexts.iterator();
276302

277303
if (iterator.hasNext()) {
@@ -287,8 +313,9 @@ void deprecated(final Set<ThreadContext> threadContexts, final String message, f
287313
// ignored; it should be removed shortly
288314
}
289315
}
290-
logger.warn(formattedMessage);
291-
} else {
316+
}
317+
318+
if (log) {
292319
logger.warn(message, params);
293320
}
294321
}

‎core/src/main/java/org/elasticsearch/common/settings/Setting.java‎

Lines changed: 19 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -19,6 +19,7 @@
1919
package org.elasticsearch.common.settings;
2020

2121
import org.apache.logging.log4j.Logger;
22+
import org.apache.lucene.util.SetOnce;
2223
import org.elasticsearch.ElasticsearchException;
2324
import org.elasticsearch.ElasticsearchParseException;
2425
import org.elasticsearch.action.support.ToXContentToBytes;
@@ -342,14 +343,27 @@ public String getRaw(Settings settings) {
342343
return settings.get(getKey(), defaultValue.apply(settings));
343344
}
344345

346+
private static SetOnce<DeprecationLogger> deprecationLogger = new SetOnce<>();
347+
348+
// we have to initialize lazily otherwise a logger would be constructed before logging is initialized
349+
private static synchronized DeprecationLogger getDeprecationLogger() {
350+
if (deprecationLogger.get() == null) {
351+
deprecationLogger.set(new DeprecationLogger(Loggers.getLogger(Settings.class)));
352+
}
353+
return deprecationLogger.get();
354+
}
355+
345356
/** Logs a deprecation warning if the setting is deprecated and used. */
346-
protected void checkDeprecation(Settings settings) {
357+
void checkDeprecation(Settings settings) {
347358
// They're using the setting, so we need to tell them to stop
348-
if (this.isDeprecated() && this.exists(settings) && settings.addDeprecatedSetting(this)) {
359+
if (this.isDeprecated() && this.exists(settings)) {
349360
// It would be convenient to show its replacement key, but replacement is often not so simple
350-
final DeprecationLogger deprecationLogger = new DeprecationLogger(Loggers.getLogger(getClass()));
351-
deprecationLogger.deprecated("[{}] setting was deprecated in Elasticsearch and will be removed in a future release! " +
352-
"See the breaking changes documentation for the next major version.", getKey());
361+
final String key = getKey();
362+
getDeprecationLogger().deprecatedAndMaybeLog(
363+
key,
364+
"[{}] setting was deprecated in Elasticsearch and will be removed in a future release! "
365+
+ "See the breaking changes documentation for the next major version.",
366+
key);
353367
}
354368
}
355369

‎core/src/main/java/org/elasticsearch/common/settings/Settings.java‎

Lines changed: 0 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -93,22 +93,6 @@ public final class Settings implements ToXContent {
9393
/** The first level of setting names. This is constructed lazily in {@link #names()}. */
9494
private final SetOnce<Set<String>> firstLevelNames = new SetOnce<>();
9595

96-
/**
97-
* The set of deprecated settings tracked by this settings object.
98-
*/
99-
private final Set<String> deprecatedSettings = Collections.newSetFromMap(new ConcurrentHashMap<>());
100-
101-
/**
102-
* Add the setting as a tracked deprecated setting.
103-
*
104-
* @param setting the deprecated setting to track
105-
* @return true if the setting was not already tracked as a deprecated setting, otherwise false
106-
*/
107-
boolean addDeprecatedSetting(final Setting setting) {
108-
assert setting.isDeprecated() && setting.exists(this) : setting.getKey();
109-
return deprecatedSettings.add(setting.getKey());
110-
}
111-
11296
/**
11397
* Setting names found in this Settings for both string and secure settings.
11498
* This is constructed lazily in {@link #keySet()}.

‎core/src/test/java/org/elasticsearch/common/settings/SettingTests.java‎

Lines changed: 0 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -154,22 +154,6 @@ public void testUpdaterIsIsolated() {
154154
assertNull(ab2.get());
155155
}
156156

157-
public void testDeprecatedSetting() {
158-
final Setting<Boolean> deprecatedSetting = Setting.boolSetting("deprecated.foo.bar", false, Property.Deprecated);
159-
final Settings settings = Settings.builder().put("deprecated.foo.bar", true).build();
160-
final int iterations = randomIntBetween(0, 128);
161-
for (int i = 0; i < iterations; i++) {
162-
deprecatedSetting.get(settings);
163-
}
164-
if (iterations > 0) {
165-
/*
166-
* This tests that we log the deprecation warning exactly one time, otherwise we would have to assert the deprecation warning
167-
* for each usage of the setting.
168-
*/
169-
assertSettingDeprecationsAndWarnings(new Setting[]{deprecatedSetting});
170-
}
171-
}
172-
173157
public void testDefault() {
174158
TimeValue defaultValue = TimeValue.timeValueMillis(randomIntBetween(0, 1000000));
175159
Setting<TimeValue> setting =

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

Lines changed: 90 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -31,6 +31,7 @@
3131
import org.elasticsearch.cli.UserException;
3232
import org.elasticsearch.cluster.ClusterName;
3333
import org.elasticsearch.common.io.PathUtils;
34+
import org.elasticsearch.common.settings.Setting;
3435
import org.elasticsearch.common.settings.Settings;
3536
import org.elasticsearch.env.Environment;
3637
import org.elasticsearch.node.Node;
@@ -42,6 +43,7 @@
4243
import java.io.StringWriter;
4344
import java.nio.file.Files;
4445
import java.nio.file.Path;
46+
import java.util.ArrayList;
4547
import java.util.List;
4648
import java.util.regex.Matcher;
4749
import java.util.regex.Pattern;
@@ -94,22 +96,102 @@ public void testLocationInfoTest() throws IOException, UserException {
9496
public void testDeprecationLogger() throws IOException, UserException {
9597
setupLogging("deprecation");
9698

97-
final DeprecationLogger deprecationLogger = new DeprecationLogger(ESLoggerFactory.getLogger("deprecation"));
99+
final DeprecationLogger deprecationLogger =
100+
new DeprecationLogger(ESLoggerFactory.getLogger("deprecation"));
101+
102+
final int deprecatedIterations = randomIntBetween(0, 256);
103+
for (int i = 0; i < deprecatedIterations; i++) {
104+
deprecationLogger.deprecated("This is a deprecation message");
105+
assertWarnings("This is a deprecation message");
106+
}
98107

99-
deprecationLogger.deprecated("This is a deprecation message");
100108
final String deprecationPath =
101109
System.getProperty("es.logs.base_path") +
102110
System.getProperty("file.separator") +
103111
System.getProperty("es.logs.cluster_name") +
104112
"_deprecation.log";
105113
final List<String> deprecationEvents = Files.readAllLines(PathUtils.get(deprecationPath));
106-
assertThat(deprecationEvents.size(), equalTo(1));
114+
assertThat(deprecationEvents.size(), equalTo(deprecatedIterations));
115+
for (int i = 0; i < deprecatedIterations; i++) {
116+
assertLogLine(
117+
deprecationEvents.get(i),
118+
Level.WARN,
119+
"org.elasticsearch.common.logging.DeprecationLogger.deprecated",
120+
"This is a deprecation message");
121+
}
122+
}
123+
124+
public void testDeprecationLoggerMaybeLog() throws IOException, UserException {
125+
setupLogging("deprecation");
126+
127+
final DeprecationLogger deprecationLogger =
128+
new DeprecationLogger(ESLoggerFactory.getLogger("deprecation"));
129+
130+
final int iterations = randomIntBetween(1, 16);
131+
132+
for (int i = 0; i < iterations; i++) {
133+
deprecationLogger.deprecatedAndMaybeLog("key", "This is a maybe logged deprecation message");
134+
assertWarnings("This is a maybe logged deprecation message");
135+
}
136+
for (int k = 0; k < 128; k++) {
137+
for (int i = 0; i < iterations; i++) {
138+
deprecationLogger.deprecatedAndMaybeLog("key" + k, "This is a maybe logged deprecation message" + k);
139+
assertWarnings("This is a maybe logged deprecation message" + k);
140+
}
141+
}
142+
for (int i = 0; i < iterations; i++) {
143+
deprecationLogger.deprecatedAndMaybeLog("key", "This is a maybe logged deprecation message");
144+
assertWarnings("This is a maybe logged deprecation message");
145+
}
146+
147+
final String deprecationPath =
148+
System.getProperty("es.logs.base_path") +
149+
System.getProperty("file.separator") +
150+
System.getProperty("es.logs.cluster_name") +
151+
"_deprecation.log";
152+
final List<String> deprecationEvents = Files.readAllLines(PathUtils.get(deprecationPath));
153+
assertThat(deprecationEvents.size(), equalTo(1 + 128 + 1));
107154
assertLogLine(
108-
deprecationEvents.get(0),
109-
Level.WARN,
110-
"org.elasticsearch.common.logging.DeprecationLogger.deprecated",
111-
"This is a deprecation message");
112-
assertWarnings("This is a deprecation message");
155+
deprecationEvents.get(0),
156+
Level.WARN,
157+
"org.elasticsearch.common.logging.DeprecationLogger.deprecated",
158+
"This is a maybe logged deprecation message");
159+
for (int k = 0; k < 128; k++) {
160+
assertLogLine(
161+
deprecationEvents.get(1 + k),
162+
Level.WARN,
163+
"org.elasticsearch.common.logging.DeprecationLogger.deprecated",
164+
"This is a maybe logged deprecation message" + k);
165+
}
166+
}
167+
168+
public void testDeprecatedSettings() throws IOException, UserException {
169+
setupLogging("settings");
170+
171+
final Setting<Boolean> setting = Setting.boolSetting("deprecated.foo", false, Setting.Property.Deprecated);
172+
final Settings settings = Settings.builder().put("deprecated.foo", true).build();
173+
174+
final int iterations = randomIntBetween(0, 128);
175+
for (int i = 0; i < iterations; i++) {
176+
setting.get(settings);
177+
assertSettingDeprecationsAndWarnings(new Setting<?>[]{setting});
178+
}
179+
180+
final String deprecationPath =
181+
System.getProperty("es.logs.base_path") +
182+
System.getProperty("file.separator") +
183+
System.getProperty("es.logs.cluster_name") +
184+
"_deprecation.log";
185+
final List<String> deprecationEvents = Files.readAllLines(PathUtils.get(deprecationPath));
186+
if (iterations > 0) {
187+
assertThat(deprecationEvents.size(), equalTo(1));
188+
assertLogLine(
189+
deprecationEvents.get(0),
190+
Level.WARN,
191+
"org.elasticsearch.common.logging.DeprecationLogger.deprecated",
192+
"\\[deprecated.foo\\] setting was deprecated in Elasticsearch and will be removed in a future release! " +
193+
"See the breaking changes documentation for the next major version.");
194+
}
113195
}
114196

115197
public void testFindAppender() throws IOException, UserException {

‎qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/settings/log4j2.properties‎

Lines changed: 25 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,25 @@
1+
appender.console.type = Console
2+
appender.console.name = console
3+
appender.console.layout.type = PatternLayout
4+
appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%m%n
5+
6+
appender.file.type = File
7+
appender.file.name = file
8+
appender.file.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}.log
9+
appender.file.layout.type = PatternLayout
10+
appender.file.layout.pattern = [%p][%l] %marker%m%n
11+
12+
rootLogger.level = info
13+
rootLogger.appenderRef.console.ref = console
14+
rootLogger.appenderRef.file.ref = file
15+
16+
appender.deprecation_file.type = File
17+
appender.deprecation_file.name = deprecation_file
18+
appender.deprecation_file.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation.log
19+
appender.deprecation_file.layout.type = PatternLayout
20+
appender.deprecation_file.layout.pattern = [%p][%l] %marker%m%n
21+
22+
logger.deprecation.name = org.elasticsearch.deprecation.common.settings
23+
logger.deprecation.level = warn
24+
logger.deprecation.appenderRef.deprecation_file.ref = deprecation_file
25+
logger.deprecation.additivity = false

‎qa/smoke-test-http/src/test/java/org/elasticsearch/http/DeprecationHttpIT.java‎

Lines changed: 8 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -30,7 +30,6 @@
3030
import org.elasticsearch.common.xcontent.XContentBuilder;
3131
import org.elasticsearch.common.xcontent.json.JsonXContent;
3232
import org.elasticsearch.plugins.Plugin;
33-
import org.elasticsearch.test.ESIntegTestCase;
3433
import org.hamcrest.Matcher;
3534

3635
import java.io.IOException;
@@ -55,7 +54,6 @@
5554
/**
5655
* Tests {@code DeprecationLogger} uses the {@code ThreadContext} to add response headers.
5756
*/
58-
@ESIntegTestCase.ClusterScope(scope = ESIntegTestCase.Scope.TEST)
5957
public class DeprecationHttpIT extends HttpSmokeTestCase {
6058

6159
@Override
@@ -127,6 +125,14 @@ public void testDeprecationWarningsAppearInHeaders() throws Exception {
127125
doTestDeprecationWarningsAppearInHeaders();
128126
}
129127

128+
public void testDeprecationHeadersDoNotGetStuck() throws Exception {
129+
doTestDeprecationWarningsAppearInHeaders();
130+
doTestDeprecationWarningsAppearInHeaders();
131+
if (rarely()) {
132+
doTestDeprecationWarningsAppearInHeaders();
133+
}
134+
}
135+
130136
/**
131137
* Run a request that receives a predictably randomized number of deprecation warnings.
132138
* <p>

0 commit comments

Comments
 (0)