Skip to content

Commit 07189c6

Browse files
committed
Ignore logging of reserved keys when passed as StructuredArgument.
1 parent 7b18029 commit 07189c6

File tree

12 files changed

+191
-23
lines changed

12 files changed

+191
-23
lines changed

powertools-logging/powertools-logging-log4j/src/main/java/org/apache/logging/log4j/layout/template/json/resolver/PowertoolsResolver.java

Lines changed: 15 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -27,7 +27,9 @@
2727

2828
import java.io.IOException;
2929
import java.util.Collections;
30+
import java.util.List;
3031
import java.util.Map;
32+
import java.util.Set;
3133
import java.util.stream.Collectors;
3234
import java.util.stream.Stream;
3335
import org.apache.logging.log4j.core.LogEvent;
@@ -45,6 +47,9 @@
4547
* to be able to recognize powertools fields in the LambdaJsonLayout.json file.
4648
*/
4749
final class PowertoolsResolver implements EventResolver {
50+
private static final Set<String> RESERVED_LOG_KEYS = Stream
51+
.concat(PowertoolsLoggedFields.stringValues().stream(), List.of("message", "level", "timestamp").stream())
52+
.collect(Collectors.toSet());
4853

4954
private static final EventResolver COLD_START_RESOLVER = new EventResolver() {
5055
@Override
@@ -191,9 +196,17 @@ public void resolve(LogEvent logEvent, JsonWriter jsonWriter) {
191196
Object[] arguments = logEvent.getMessage().getParameters();
192197
if (arguments != null) {
193198
stream(arguments).filter(StructuredArgument.class::isInstance).forEach(argument -> {
194-
serializer.writeRaw(',');
195199
try {
196-
((StructuredArgument) argument).writeTo(serializer);
200+
final StructuredArgument structArg = (StructuredArgument) argument;
201+
final Iterable<String> logKeys = structArg.keys();
202+
// If any of the logKeys are a reserved key we are going to ignore the argument
203+
for (final String logKey : logKeys) {
204+
if (RESERVED_LOG_KEYS.contains(logKey)) {
205+
return;
206+
}
207+
}
208+
serializer.writeRaw(',');
209+
structArg.writeTo(serializer);
197210
} catch (IOException e) {
198211
System.err.printf("Failed to encode log event, error: %s.%n", e.getMessage());
199212
}

powertools-logging/powertools-logging-log4j/src/test/java/org/apache/logging/log4j/layout/template/json/resolver/PowertoolsResolverArgumentsTest.java

Lines changed: 16 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -35,6 +35,8 @@
3535
import org.junit.jupiter.api.Test;
3636
import org.mockito.Mock;
3737
import org.slf4j.MDC;
38+
39+
import software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields;
3840
import software.amazon.lambda.powertools.logging.internal.handler.PowertoolsArguments;
3941

4042
@Order(2)
@@ -83,9 +85,14 @@ void shouldLogArgumentsAsJsonWhenUsingRawJson() {
8385
// THEN
8486
File logFile = new File("target/logfile.json");
8587
assertThat(contentOf(logFile))
86-
.contains("\"input\":{\"awsRegion\":\"eu-west-1\",\"body\":\"plop\",\"eventSource\":\"eb\",\"messageAttributes\":{\"keyAttribute\":{\"stringListValues\":[\"val1\",\"val2\",\"val3\"]}},\"messageId\":\"1212abcd\"}")
88+
.contains(
89+
"\"input\":{\"awsRegion\":\"eu-west-1\",\"body\":\"plop\",\"eventSource\":\"eb\",\"messageAttributes\":{\"keyAttribute\":{\"stringListValues\":[\"val1\",\"val2\",\"val3\"]}},\"messageId\":\"1212abcd\"}")
8790
.contains("\"message\":\"1212abcd\"")
8891
.contains("\"message\":\"Message body = plop and id = \\\"1212abcd\\\"\"");
92+
// Reserved keys should be ignored
93+
PowertoolsLoggedFields.stringValues().stream().forEach(reservedKey -> {
94+
assertThat(contentOf(logFile)).doesNotContain("\"" + reservedKey + "\":\"shouldBeIgnored\"");
95+
});
8996
}
9097

9198
@Test
@@ -107,9 +114,15 @@ void shouldLogArgumentsAsJsonWhenUsingKeyValue() {
107114
// THEN
108115
File logFile = new File("target/logfile.json");
109116
assertThat(contentOf(logFile))
110-
.contains("\"input\":{\"awsRegion\":\"eu-west-1\",\"body\":\"plop\",\"eventSource\":\"eb\",\"messageAttributes\":{\"keyAttribute\":{\"stringListValues\":[\"val1\",\"val2\",\"val3\"]}},\"messageId\":\"1212abcd\"}")
117+
.contains(
118+
"\"input\":{\"awsRegion\":\"eu-west-1\",\"body\":\"plop\",\"eventSource\":\"eb\",\"messageAttributes\":{\"keyAttribute\":{\"stringListValues\":[\"val1\",\"val2\",\"val3\"]}},\"messageId\":\"1212abcd\"}")
111119
.contains("\"message\":\"1212abcd\"")
112120
.contains("\"message\":\"Message body = plop and id = \\\"1212abcd\\\"\"");
121+
122+
// Reserved keys should be ignored
123+
PowertoolsLoggedFields.stringValues().stream().forEach(reservedKey -> {
124+
assertThat(contentOf(logFile)).doesNotContain("\"" + reservedKey + "\":\"shouldBeIgnored\"");
125+
});
113126
}
114127

115128
private void setupContext() {
@@ -119,4 +132,4 @@ private void setupContext() {
119132
when(context.getMemoryLimitInMB()).thenReturn(10);
120133
when(context.getAwsRequestId()).thenReturn("RequestId");
121134
}
122-
}
135+
}

powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/internal/handler/PowertoolsArguments.java

Lines changed: 28 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -16,15 +16,21 @@
1616

1717
import static software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields.CORRELATION_ID;
1818

19+
import java.util.HashMap;
20+
import java.util.Map;
21+
22+
import org.slf4j.Logger;
23+
import org.slf4j.LoggerFactory;
24+
import org.slf4j.MDC;
25+
1926
import com.amazonaws.services.lambda.runtime.Context;
2027
import com.amazonaws.services.lambda.runtime.RequestHandler;
2128
import com.amazonaws.services.lambda.runtime.events.SQSEvent;
2229
import com.fasterxml.jackson.core.JsonProcessingException;
23-
import org.slf4j.Logger;
24-
import org.slf4j.LoggerFactory;
25-
import org.slf4j.MDC;
30+
2631
import software.amazon.lambda.powertools.logging.Logging;
2732
import software.amazon.lambda.powertools.logging.argument.StructuredArguments;
33+
import software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields;
2834
import software.amazon.lambda.powertools.utilities.JsonConfig;
2935

3036
public class PowertoolsArguments implements RequestHandler<SQSEvent.SQSMessage, String> {
@@ -41,11 +47,27 @@ public String handleRequest(SQSEvent.SQSMessage input, Context context) {
4147
try {
4248
MDC.put(CORRELATION_ID.getName(), input.getMessageId());
4349
if (argumentFormat == ArgumentFormat.JSON) {
44-
LOG.debug("SQS Event", StructuredArguments.json("input",
45-
JsonConfig.get().getObjectMapper().writeValueAsString(input)));
50+
LOG.debug("SQS Event",
51+
StructuredArguments.json("input",
52+
JsonConfig.get().getObjectMapper().writeValueAsString(input)),
53+
// function_name is a reserved key by PowertoolsLoggedFields and should be omitted
54+
StructuredArguments.entry("function_name", "shouldBeIgnored"));
4655
} else {
47-
LOG.debug("SQS Event", StructuredArguments.entry("input", input));
56+
LOG.debug("SQS Event",
57+
StructuredArguments.entry("input", input),
58+
// function_name is a reserved key by PowertoolsLoggedFields and should be omitted
59+
StructuredArguments.entry("function_name", "shouldBeIgnored"));
60+
}
61+
62+
// Attempt logging all reserved keys, the values should not be overwritten by "shouldBeIgnored"
63+
final Map<String, String> reservedKeysMap = new HashMap<>();
64+
for (String field : PowertoolsLoggedFields.stringValues()) {
65+
reservedKeysMap.put(field, "shouldBeIgnored");
4866
}
67+
reservedKeysMap.put("message", "shouldBeIgnored");
68+
reservedKeysMap.put("level", "shouldBeIgnored");
69+
reservedKeysMap.put("timestamp", "shouldBeIgnored");
70+
LOG.debug("Reserved keys", StructuredArguments.entries(reservedKeysMap));
4971
LOG.debug("{}", input.getMessageId());
5072
LOG.warn("Message body = {} and id = \"{}\"", input.getBody(), input.getMessageId());
5173
} catch (JsonProcessingException e) {

powertools-logging/powertools-logging-logback/src/main/java/software/amazon/lambda/powertools/logging/logback/JsonUtils.java

Lines changed: 18 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -19,9 +19,14 @@
1919
import java.text.DateFormat;
2020
import java.text.SimpleDateFormat;
2121
import java.util.Date;
22+
import java.util.List;
2223
import java.util.Map;
24+
import java.util.Set;
2325
import java.util.TimeZone;
2426
import java.util.TreeMap;
27+
import java.util.stream.Collectors;
28+
import java.util.stream.Stream;
29+
2530
import software.amazon.lambda.powertools.logging.argument.StructuredArgument;
2631
import software.amazon.lambda.powertools.logging.internal.JsonSerializer;
2732
import software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields;
@@ -30,13 +35,16 @@
3035
* Json tools to serialize common fields
3136
*/
3237
final class JsonUtils {
38+
private static final Set<String> RESERVED_LOG_KEYS = Stream
39+
.concat(PowertoolsLoggedFields.stringValues().stream(), List.of("message", "level", "timestamp").stream())
40+
.collect(Collectors.toSet());
3341

3442
private JsonUtils() {
3543
// static utils
3644
}
3745

3846
static void serializeTimestamp(JsonSerializer generator, long timestamp, String timestampFormat,
39-
String timestampFormatTimezoneId, String timestampAttributeName) {
47+
String timestampFormatTimezoneId, String timestampAttributeName) {
4048
String formattedTimestamp;
4149
if (timestampFormat == null || timestamp < 0) {
4250
formattedTimestamp = String.valueOf(timestamp);
@@ -77,8 +85,16 @@ static void serializeArguments(ILoggingEvent event, JsonSerializer serializer) t
7785
if (arguments != null) {
7886
for (Object argument : arguments) {
7987
if (argument instanceof StructuredArgument) {
88+
final StructuredArgument structArg = (StructuredArgument) argument;
89+
final Iterable<String> logKeys = structArg.keys();
90+
// If any of the logKeys are a reserved key we are going to ignore the argument
91+
for (final String logKey : logKeys) {
92+
if (RESERVED_LOG_KEYS.contains(logKey)) {
93+
return;
94+
}
95+
}
8096
serializer.writeRaw(',');
81-
((StructuredArgument) argument).writeTo(serializer);
97+
structArg.writeTo(serializer);
8298
}
8399
}
84100
}

powertools-logging/powertools-logging-logback/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaJsonEncoderTest.java

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -29,6 +29,8 @@
2929
import com.amazonaws.services.lambda.runtime.Context;
3030
import com.amazonaws.services.lambda.runtime.events.SQSEvent;
3131
import com.fasterxml.jackson.databind.ObjectMapper;
32+
import com.fasterxml.jackson.databind.util.JSONPObject;
33+
3234
import java.io.ByteArrayInputStream;
3335
import java.io.ByteArrayOutputStream;
3436
import java.io.File;
@@ -126,6 +128,10 @@ void shouldLogArgumentsAsJsonWhenUsingRawJson() {
126128
.contains("\"input\":{\"awsRegion\":\"eu-west-1\",\"body\":\"plop\",\"eventSource\":\"eb\",\"messageAttributes\":{\"keyAttribute\":{\"stringListValues\":[\"val1\",\"val2\",\"val3\"]}},\"messageId\":\"1212abcd\"}")
127129
.contains("\"message\":\"1212abcd\"")
128130
.contains("\"message\":\"Message body = plop and id = \"1212abcd\"\"");
131+
// Reserved keys should be ignored
132+
PowertoolsLoggedFields.stringValues().stream().forEach(reservedKey -> {
133+
assertThat(contentOf(logFile)).doesNotContain("\"" + reservedKey + "\":\"shouldBeIgnored\"");
134+
});
129135
}
130136

131137
@Test
@@ -150,6 +156,10 @@ void shouldLogArgumentsAsJsonWhenUsingKeyValue() {
150156
.contains("\"input\":{\"awsRegion\":\"eu-west-1\",\"body\":\"plop\",\"eventSource\":\"eb\",\"messageAttributes\":{\"keyAttribute\":{\"stringListValues\":[\"val1\",\"val2\",\"val3\"]}},\"messageId\":\"1212abcd\"}")
151157
.contains("\"message\":\"1212abcd\"")
152158
.contains("\"message\":\"Message body = plop and id = \"1212abcd\"\"");
159+
// Reserved keys should be ignored
160+
PowertoolsLoggedFields.stringValues().stream().forEach(reservedKey -> {
161+
assertThat(contentOf(logFile)).doesNotContain("\"" + reservedKey + "\":\"shouldBeIgnored\"");
162+
});
153163
}
154164

155165
private final LoggingEvent loggingEvent = new LoggingEvent("fqcn", logger, Level.INFO, "message", null, null);

powertools-logging/powertools-logging-logback/src/test/java/software/amazon/lambda/powertools/logging/internal/handler/PowertoolsArguments.java

Lines changed: 28 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -16,15 +16,21 @@
1616

1717
import static software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields.CORRELATION_ID;
1818

19+
import java.util.HashMap;
20+
import java.util.Map;
21+
22+
import org.slf4j.Logger;
23+
import org.slf4j.LoggerFactory;
24+
import org.slf4j.MDC;
25+
1926
import com.amazonaws.services.lambda.runtime.Context;
2027
import com.amazonaws.services.lambda.runtime.RequestHandler;
2128
import com.amazonaws.services.lambda.runtime.events.SQSEvent;
2229
import com.fasterxml.jackson.core.JsonProcessingException;
23-
import org.slf4j.Logger;
24-
import org.slf4j.LoggerFactory;
25-
import org.slf4j.MDC;
30+
2631
import software.amazon.lambda.powertools.logging.Logging;
2732
import software.amazon.lambda.powertools.logging.argument.StructuredArguments;
33+
import software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields;
2834
import software.amazon.lambda.powertools.utilities.JsonConfig;
2935

3036
public class PowertoolsArguments implements RequestHandler<SQSEvent.SQSMessage, String> {
@@ -41,11 +47,27 @@ public String handleRequest(SQSEvent.SQSMessage input, Context context) {
4147
try {
4248
MDC.put(CORRELATION_ID.getName(), input.getMessageId());
4349
if (argumentFormat == ArgumentFormat.JSON) {
44-
LOG.debug("SQS Event", StructuredArguments.json("input",
45-
JsonConfig.get().getObjectMapper().writeValueAsString(input)));
50+
LOG.debug("SQS Event",
51+
StructuredArguments.json("input",
52+
JsonConfig.get().getObjectMapper().writeValueAsString(input)),
53+
// function_name is a reserved key by PowertoolsLoggedFields and should be omitted
54+
StructuredArguments.entry("function_name", "shouldBeIgnored"));
4655
} else {
47-
LOG.debug("SQS Event", StructuredArguments.entry("input", input));
56+
LOG.debug("SQS Event",
57+
StructuredArguments.entry("input", input),
58+
// function_name is a reserved key by PowertoolsLoggedFields and should be omitted
59+
StructuredArguments.entry("function_name", "shouldBeIgnored"));
60+
}
61+
62+
// Attempt logging all reserved keys, the values should not be overwritten by "shouldBeIgnored"
63+
final Map<String, String> reservedKeysMap = new HashMap<>();
64+
for (String field : PowertoolsLoggedFields.stringValues()) {
65+
reservedKeysMap.put(field, "shouldBeIgnored");
4866
}
67+
reservedKeysMap.put("message", "shouldBeIgnored");
68+
reservedKeysMap.put("level", "shouldBeIgnored");
69+
reservedKeysMap.put("timestamp", "shouldBeIgnored");
70+
LOG.debug("Reserved keys", StructuredArguments.entries(reservedKeysMap));
4971
LOG.debug("{}", input.getMessageId());
5072
LOG.warn("Message body = {} and id = \"{}\"", input.getBody(), input.getMessageId());
5173
} catch (JsonProcessingException e) {

powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/argument/ArrayArgument.java

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,8 @@
1515
package software.amazon.lambda.powertools.logging.argument;
1616

1717
import java.util.Objects;
18+
import java.util.Set;
19+
1820
import software.amazon.lambda.powertools.logging.internal.JsonSerializer;
1921

2022
/**
@@ -40,4 +42,9 @@ public void writeTo(JsonSerializer serializer) {
4042
public String toString() {
4143
return key + "=" + StructuredArguments.toString(values);
4244
}
45+
46+
@Override
47+
public Iterable<String> keys() {
48+
return Set.of(key);
49+
}
4350
}

powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/argument/JsonArgument.java

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,8 @@
1515
package software.amazon.lambda.powertools.logging.argument;
1616

1717
import java.util.Objects;
18+
import java.util.Set;
19+
1820
import software.amazon.lambda.powertools.logging.internal.JsonSerializer;
1921

2022
/**
@@ -39,4 +41,9 @@ public void writeTo(JsonSerializer serializer) {
3941
public String toString() {
4042
return key + "=" + rawJson;
4143
}
44+
45+
@Override
46+
public Iterable<String> keys() {
47+
return Set.of(key);
48+
}
4249
}

powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/argument/KeyValueArgument.java

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,8 @@
1515
package software.amazon.lambda.powertools.logging.argument;
1616

1717
import java.util.Objects;
18+
import java.util.Set;
19+
1820
import software.amazon.lambda.powertools.logging.internal.JsonSerializer;
1921

2022
/**
@@ -39,6 +41,11 @@ public String toString() {
3941
return key + "=" + StructuredArguments.toString(value);
4042
}
4143

44+
@Override
45+
public Iterable<String> keys() {
46+
return Set.of(getKey());
47+
}
48+
4249
public String getKey() {
4350
return key;
4451
}

powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/argument/MapArgument.java

Lines changed: 21 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -15,8 +15,12 @@
1515
package software.amazon.lambda.powertools.logging.argument;
1616

1717
import java.util.HashMap;
18+
import java.util.Iterator;
1819
import java.util.Map;
20+
import java.util.stream.Collectors;
21+
1922
import software.amazon.lambda.powertools.logging.internal.JsonSerializer;
23+
import java.util.Set;
2024

2125
/**
2226
* See {@link StructuredArguments#entries(Map)}
@@ -35,8 +39,13 @@ public MapArgument(Map<?, ?> map) {
3539
@Override
3640
public void writeTo(JsonSerializer serializer) {
3741
if (map != null) {
38-
for (Map.Entry<?, ?> entry : map.entrySet()) {
42+
for (Iterator<? extends Map.Entry<?, ?>> entries = map.entrySet().iterator(); entries.hasNext();) {
43+
Map.Entry<?, ?> entry = entries.next();
3944
serializer.writeObjectField(String.valueOf(entry.getKey()), entry.getValue());
45+
// If the map has more than one entry, we need to print a (comma) separator to avoid breaking the JSON
46+
if (entries.hasNext()) {
47+
serializer.writeSeparator();
48+
}
4049
}
4150
}
4251
}
@@ -45,4 +54,15 @@ public void writeTo(JsonSerializer serializer) {
4554
public String toString() {
4655
return String.valueOf(map);
4756
}
57+
58+
@Override
59+
public Iterable<String> keys() {
60+
if (map == null) {
61+
return Set.of();
62+
}
63+
64+
// Object::toString is used to convert the key to a string, as per the behavior of Map.toString() in case the
65+
// key is not already a String.
66+
return map.keySet().stream().map(Object::toString).collect(Collectors.toSet());
67+
}
4868
}

0 commit comments

Comments
 (0)