Skip to content

fix(logging): Prevent accidental overwriting of reserved keys via structured arguments #1822

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

Merged
merged 10 commits into from
Apr 24, 2025
Merged

fix(logging): Prevent accidental overwriting of reserved keys via structured arguments #1822

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
10 commits
Select commit Hold shift + click to select a range
07189c6
Ignore logging of reserved keys when passed as StructuredArgument.
phipag Apr 23, 2025
70459e5
Add error to reserved log keys.
phipag Apr 23, 2025
f784886
Update docs with a warning about logging of reserved keys when using …
phipag Apr 23, 2025
a5e6b09
Update docs with warning in MDC section as well.
phipag Apr 23, 2025
84e9557
Update product name in documentation.
phipag Apr 24, 2025
2657657
Make StructuredArgument implementations package private. They should …
phipag Apr 24, 2025
58bb26d
Make StructuredArgument interface public and remove package private d…
phipag Apr 24, 2025
9f16c46
Move reserved key logic from logging implementation to StructuredArgu…
phipag Apr 24, 2025
ab9c44a
Remove .keys() method again from StructuredArgument interface. It is …
phipag Apr 24, 2025
66cad55
Update documentation warnings regarding logging of reserved keys.
phipag Apr 24, 2025
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
9 changes: 9 additions & 0 deletions docs/core/logging.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -354,6 +354,9 @@ Your logs will always include the following keys in your structured logging:
| **xray_trace_id** | String | "1-5759e988-bd862e3fe1be46a994272793" | X-Ray Trace ID when [Tracing is enabled](https://docs.aws.amazon.com/lambda/latest/dg/services-xray.html){target="_blank"} |
| **error** | Map | `{ "name": "InvalidAmountException", "message": "Amount must be superior to 0", "stack": "at..." }` | Eventual exception (e.g. when doing `logger.error("Error", new InvalidAmountException("Amount must be superior to 0"));`) |

???+ note
If you emit a log message with a key that matches one of the [standard structured keys](#standard-structured-keys) or one of the [additional structured keys](#additional-structured-keys), the Logger will log a warning message and ignore the key.

## Additional structured keys

### Logging Lambda context information
Expand Down Expand Up @@ -640,6 +643,9 @@ To append additional keys in your logs, you can use the `StructuredArguments` cl
}
```

???+ warning "Do not use reserved keys in `StructuredArguments`"
If the key name of your structured argument matches any of the [standard structured keys](#standard-structured-keys) or any of the [additional structured keys](#additional-structured-keys), the Logger will log a warning message and ignore the key. This is to protect you from accidentally overwriting reserved keys such as the log level or Lambda context information.

**Using MDC**

Mapped Diagnostic Context (MDC) is essentially a Key-Value store. It is supported by the [SLF4J API](https://www.slf4j.org/manual.html#mdc){target="_blank"},
Expand All @@ -650,6 +656,9 @@ Mapped Diagnostic Context (MDC) is essentially a Key-Value store. It is supporte
???+ warning "Custom keys stored in the MDC are persisted across warm invocations"
Always set additional keys as part of your handler method to ensure they have the latest value, or explicitly clear them with [`clearState=true`](#clearing-state).

???+ warning "Do not add reserved keys to MDC"
Avoid adding any of the keys listed in [standard structured keys](#standard-structured-keys) and [additional structured keys](#additional-structured-keys) to your MDC. This may cause unindented behavior and will overwrite the context set by the Logger. Unlike with `StructuredArguments`, the Logger will **not** ignore reserved keys set via MDC.


### Removing additional keys

Expand Down
29 changes: 15 additions & 14 deletions .../main/java/org/apache/logging/log4j/layout/template/json/resolver/PowertoolsResolver.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -191,8 +191,8 @@ public void resolve(LogEvent logEvent, JsonWriter jsonWriter) {
Object[] arguments = logEvent.getMessage().getParameters();
if (arguments != null) {
stream(arguments).filter(StructuredArgument.class::isInstance).forEach(argument -> {
serializer.writeRaw(',');
try {
serializer.writeRaw(',');
((StructuredArgument) argument).writeTo(serializer);
} catch (IOException e) {
System.err.printf("Failed to encode log event, error: %s.%n", e.getMessage());
Expand All @@ -204,19 +204,20 @@ public void resolve(LogEvent logEvent, JsonWriter jsonWriter) {

private final EventResolver internalResolver;

private static final Map<String, EventResolver> eventResolverMap = Collections.unmodifiableMap(Stream.of(new Object[][] {
{ SERVICE.getName(), SERVICE_RESOLVER },
{ FUNCTION_NAME.getName(), FUNCTION_NAME_RESOLVER },
{ FUNCTION_VERSION.getName(), FUNCTION_VERSION_RESOLVER },
{ FUNCTION_ARN.getName(), FUNCTION_ARN_RESOLVER },
{ FUNCTION_MEMORY_SIZE.getName(), FUNCTION_MEMORY_RESOLVER },
{ FUNCTION_REQUEST_ID.getName(), FUNCTION_REQ_RESOLVER },
{ FUNCTION_COLD_START.getName(), COLD_START_RESOLVER },
{ FUNCTION_TRACE_ID.getName(), XRAY_TRACE_RESOLVER },
{ SAMPLING_RATE.getName(), SAMPLING_RATE_RESOLVER },
{ "region", REGION_RESOLVER },
{ "account_id", ACCOUNT_ID_RESOLVER }
}).collect(Collectors.toMap(data -> (String) data[0], data -> (EventResolver) data[1])));
private static final Map<String, EventResolver> eventResolverMap = Collections
.unmodifiableMap(Stream.of(new Object[][] {
{ SERVICE.getName(), SERVICE_RESOLVER },
{ FUNCTION_NAME.getName(), FUNCTION_NAME_RESOLVER },
{ FUNCTION_VERSION.getName(), FUNCTION_VERSION_RESOLVER },
{ FUNCTION_ARN.getName(), FUNCTION_ARN_RESOLVER },
{ FUNCTION_MEMORY_SIZE.getName(), FUNCTION_MEMORY_RESOLVER },
{ FUNCTION_REQUEST_ID.getName(), FUNCTION_REQ_RESOLVER },
{ FUNCTION_COLD_START.getName(), COLD_START_RESOLVER },
{ FUNCTION_TRACE_ID.getName(), XRAY_TRACE_RESOLVER },
{ SAMPLING_RATE.getName(), SAMPLING_RATE_RESOLVER },
{ "region", REGION_RESOLVER },
{ "account_id", ACCOUNT_ID_RESOLVER }
}).collect(Collectors.toMap(data -> (String) data[0], data -> (EventResolver) data[1])));


PowertoolsResolver(final TemplateResolverConfig config) {
Expand Down
25 changes: 22 additions & 3 deletions ...g/apache/logging/log4j/layout/template/json/resolver/PowertoolsResolverArgumentsTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -35,6 +35,8 @@
import org.junit.jupiter.api.Test;
import org.mockito.Mock;
import org.slf4j.MDC;

import software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields;
import software.amazon.lambda.powertools.logging.internal.handler.PowertoolsArguments;

@Order(2)
Expand Down Expand Up @@ -83,9 +85,17 @@ void shouldLogArgumentsAsJsonWhenUsingRawJson() {
// THEN
File logFile = new File("target/logfile.json");
assertThat(contentOf(logFile))
.contains("\"input\":{\"awsRegion\":\"eu-west-1\",\"body\":\"plop\",\"eventSource\":\"eb\",\"messageAttributes\":{\"keyAttribute\":{\"stringListValues\":[\"val1\",\"val2\",\"val3\"]}},\"messageId\":\"1212abcd\"}")
.contains(
"\"input\":{\"awsRegion\":\"eu-west-1\",\"body\":\"plop\",\"eventSource\":\"eb\",\"messageAttributes\":{\"keyAttribute\":{\"stringListValues\":[\"val1\",\"val2\",\"val3\"]}},\"messageId\":\"1212abcd\"}")
.contains("\"message\":\"1212abcd\"")
.contains("\"message\":\"Message body = plop and id = \\\"1212abcd\\\"\"");
// Reserved keys should be ignored
PowertoolsLoggedFields.stringValues().stream().forEach(reservedKey -> {
assertThat(contentOf(logFile)).doesNotContain("\"" + reservedKey + "\":\"shouldBeIgnored\"");
assertThat(contentOf(logFile)).contains(
"\"message\":\"Attempted to use reserved key '" + reservedKey
+ "' in structured argument. This key will be ignored.\"");
});
}

@Test
Expand All @@ -107,9 +117,18 @@ void shouldLogArgumentsAsJsonWhenUsingKeyValue() {
// THEN
File logFile = new File("target/logfile.json");
assertThat(contentOf(logFile))
.contains("\"input\":{\"awsRegion\":\"eu-west-1\",\"body\":\"plop\",\"eventSource\":\"eb\",\"messageAttributes\":{\"keyAttribute\":{\"stringListValues\":[\"val1\",\"val2\",\"val3\"]}},\"messageId\":\"1212abcd\"}")
.contains(
"\"input\":{\"awsRegion\":\"eu-west-1\",\"body\":\"plop\",\"eventSource\":\"eb\",\"messageAttributes\":{\"keyAttribute\":{\"stringListValues\":[\"val1\",\"val2\",\"val3\"]}},\"messageId\":\"1212abcd\"}")
.contains("\"message\":\"1212abcd\"")
.contains("\"message\":\"Message body = plop and id = \\\"1212abcd\\\"\"");

// Reserved keys should be ignored
PowertoolsLoggedFields.stringValues().stream().forEach(reservedKey -> {
assertThat(contentOf(logFile)).doesNotContain("\"" + reservedKey + "\":\"shouldBeIgnored\"");
assertThat(contentOf(logFile)).contains(
"\"message\":\"Attempted to use reserved key '" + reservedKey
+ "' in structured argument. This key will be ignored.\"");
});
}

private void setupContext() {
Expand All @@ -119,4 +138,4 @@ private void setupContext() {
when(context.getMemoryLimitInMB()).thenReturn(10);
when(context.getAwsRequestId()).thenReturn("RequestId");
}
}
}
34 changes: 28 additions & 6 deletions .../java/software/amazon/lambda/powertools/logging/internal/handler/PowertoolsArguments.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -16,15 +16,21 @@

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

import java.util.HashMap;
import java.util.Map;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;

import com.amazonaws.services.lambda.runtime.Context;
import com.amazonaws.services.lambda.runtime.RequestHandler;
import com.amazonaws.services.lambda.runtime.events.SQSEvent;
import com.fasterxml.jackson.core.JsonProcessingException;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;

import software.amazon.lambda.powertools.logging.Logging;
import software.amazon.lambda.powertools.logging.argument.StructuredArguments;
import software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields;
import software.amazon.lambda.powertools.utilities.JsonConfig;

public class PowertoolsArguments implements RequestHandler<SQSEvent.SQSMessage, String> {
Expand All @@ -41,11 +47,27 @@ public String handleRequest(SQSEvent.SQSMessage input, Context context) {
try {
MDC.put(CORRELATION_ID.getName(), input.getMessageId());
if (argumentFormat == ArgumentFormat.JSON) {
LOG.debug("SQS Event", StructuredArguments.json("input",
JsonConfig.get().getObjectMapper().writeValueAsString(input)));
LOG.debug("SQS Event",
StructuredArguments.json("input",
JsonConfig.get().getObjectMapper().writeValueAsString(input)),
// function_name is a reserved key by PowertoolsLoggedFields and should be omitted
StructuredArguments.entry("function_name", "shouldBeIgnored"));
} else {
LOG.debug("SQS Event", StructuredArguments.entry("input", input));
LOG.debug("SQS Event",
StructuredArguments.entry("input", input),
// function_name is a reserved key by PowertoolsLoggedFields and should be omitted
StructuredArguments.entry("function_name", "shouldBeIgnored"));
}

// Attempt logging all reserved keys, the values should not be overwritten by "shouldBeIgnored"
final Map<String, String> reservedKeysMap = new HashMap<>();
for (String field : PowertoolsLoggedFields.stringValues()) {
reservedKeysMap.put(field, "shouldBeIgnored");
}
reservedKeysMap.put("message", "shouldBeIgnored");
reservedKeysMap.put("level", "shouldBeIgnored");
reservedKeysMap.put("timestamp", "shouldBeIgnored");
LOG.debug("Reserved keys", StructuredArguments.entries(reservedKeysMap));
LOG.debug("{}", input.getMessageId());
LOG.warn("Message body = {} and id = \"{}\"", input.getBody(), input.getMessageId());
} catch (JsonProcessingException e) {
Expand Down
3 changes: 2 additions & 1 deletion ...ng-logback/src/main/java/software/amazon/lambda/powertools/logging/logback/JsonUtils.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@
import java.util.Map;
import java.util.TimeZone;
import java.util.TreeMap;

import software.amazon.lambda.powertools.logging.argument.StructuredArgument;
import software.amazon.lambda.powertools.logging.internal.JsonSerializer;
import software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields;
Expand All @@ -36,7 +37,7 @@ private JsonUtils() {
}

static void serializeTimestamp(JsonSerializer generator, long timestamp, String timestampFormat,
String timestampFormatTimezoneId, String timestampAttributeName) {
String timestampFormatTimezoneId, String timestampAttributeName) {
String formattedTimestamp;
if (timestampFormat == null || timestamp < 0) {
formattedTimestamp = String.valueOf(timestamp);
Expand Down
16 changes: 16 additions & 0 deletions ...c/test/java/software/amazon/lambda/powertools/logging/internal/LambdaJsonEncoderTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,8 @@
import com.amazonaws.services.lambda.runtime.Context;
import com.amazonaws.services.lambda.runtime.events.SQSEvent;
import com.fasterxml.jackson.databind.ObjectMapper;
import com.fasterxml.jackson.databind.util.JSONPObject;

import java.io.ByteArrayInputStream;
import java.io.ByteArrayOutputStream;
import java.io.File;
Expand Down Expand Up @@ -126,6 +128,13 @@ void shouldLogArgumentsAsJsonWhenUsingRawJson() {
.contains("\"input\":{\"awsRegion\":\"eu-west-1\",\"body\":\"plop\",\"eventSource\":\"eb\",\"messageAttributes\":{\"keyAttribute\":{\"stringListValues\":[\"val1\",\"val2\",\"val3\"]}},\"messageId\":\"1212abcd\"}")
.contains("\"message\":\"1212abcd\"")
.contains("\"message\":\"Message body = plop and id = \"1212abcd\"\"");
// Reserved keys should be ignored
PowertoolsLoggedFields.stringValues().stream().forEach(reservedKey -> {
assertThat(contentOf(logFile)).doesNotContain("\"" + reservedKey + "\":\"shouldBeIgnored\"");
assertThat(contentOf(logFile)).contains(
"\"message\":\"Attempted to use reserved key '" + reservedKey
+ "' in structured argument. This key will be ignored.\"");
});
}

@Test
Expand All @@ -150,6 +159,13 @@ void shouldLogArgumentsAsJsonWhenUsingKeyValue() {
.contains("\"input\":{\"awsRegion\":\"eu-west-1\",\"body\":\"plop\",\"eventSource\":\"eb\",\"messageAttributes\":{\"keyAttribute\":{\"stringListValues\":[\"val1\",\"val2\",\"val3\"]}},\"messageId\":\"1212abcd\"}")
.contains("\"message\":\"1212abcd\"")
.contains("\"message\":\"Message body = plop and id = \"1212abcd\"\"");
// Reserved keys should be ignored
PowertoolsLoggedFields.stringValues().stream().forEach(reservedKey -> {
assertThat(contentOf(logFile)).doesNotContain("\"" + reservedKey + "\":\"shouldBeIgnored\"");
assertThat(contentOf(logFile)).contains(
"\"message\":\"Attempted to use reserved key '" + reservedKey
+ "' in structured argument. This key will be ignored.\"");
});
}

private final LoggingEvent loggingEvent = new LoggingEvent("fqcn", logger, Level.INFO, "message", null, null);
Expand Down
34 changes: 28 additions & 6 deletions .../java/software/amazon/lambda/powertools/logging/internal/handler/PowertoolsArguments.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -16,15 +16,21 @@

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

import java.util.HashMap;
import java.util.Map;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;

import com.amazonaws.services.lambda.runtime.Context;
import com.amazonaws.services.lambda.runtime.RequestHandler;
import com.amazonaws.services.lambda.runtime.events.SQSEvent;
import com.fasterxml.jackson.core.JsonProcessingException;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;

import software.amazon.lambda.powertools.logging.Logging;
import software.amazon.lambda.powertools.logging.argument.StructuredArguments;
import software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields;
import software.amazon.lambda.powertools.utilities.JsonConfig;

public class PowertoolsArguments implements RequestHandler<SQSEvent.SQSMessage, String> {
Expand All @@ -41,11 +47,27 @@ public String handleRequest(SQSEvent.SQSMessage input, Context context) {
try {
MDC.put(CORRELATION_ID.getName(), input.getMessageId());
if (argumentFormat == ArgumentFormat.JSON) {
LOG.debug("SQS Event", StructuredArguments.json("input",
JsonConfig.get().getObjectMapper().writeValueAsString(input)));
LOG.debug("SQS Event",
StructuredArguments.json("input",
JsonConfig.get().getObjectMapper().writeValueAsString(input)),
// function_name is a reserved key by PowertoolsLoggedFields and should be omitted
StructuredArguments.entry("function_name", "shouldBeIgnored"));
} else {
LOG.debug("SQS Event", StructuredArguments.entry("input", input));
LOG.debug("SQS Event",
StructuredArguments.entry("input", input),
// function_name is a reserved key by PowertoolsLoggedFields and should be omitted
StructuredArguments.entry("function_name", "shouldBeIgnored"));
}

// Attempt logging all reserved keys, the values should not be overwritten by "shouldBeIgnored"
final Map<String, String> reservedKeysMap = new HashMap<>();
for (String field : PowertoolsLoggedFields.stringValues()) {
reservedKeysMap.put(field, "shouldBeIgnored");
}
reservedKeysMap.put("message", "shouldBeIgnored");
reservedKeysMap.put("level", "shouldBeIgnored");
reservedKeysMap.put("timestamp", "shouldBeIgnored");
LOG.debug("Reserved keys", StructuredArguments.entries(reservedKeysMap));
LOG.debug("{}", input.getMessageId());
LOG.warn("Message body = {} and id = \"{}\"", input.getBody(), input.getMessageId());
} catch (JsonProcessingException e) {
Expand Down
4 changes: 3 additions & 1 deletion ...gging/src/main/java/software/amazon/lambda/powertools/logging/argument/ArrayArgument.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,12 +15,13 @@
package software.amazon.lambda.powertools.logging.argument;

import java.util.Objects;

import software.amazon.lambda.powertools.logging.internal.JsonSerializer;

/**
* See {@link StructuredArguments#array(String, Object...)}
*/
public class ArrayArgument implements StructuredArgument {
class ArrayArgument implements StructuredArgument {
private final String key;
private final Object[] values;

Expand All @@ -40,4 +41,5 @@ public void writeTo(JsonSerializer serializer) {
public String toString() {
return key + "=" + StructuredArguments.toString(values);
}

}
4 changes: 3 additions & 1 deletion ...ogging/src/main/java/software/amazon/lambda/powertools/logging/argument/JsonArgument.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,12 +15,13 @@
package software.amazon.lambda.powertools.logging.argument;

import java.util.Objects;

import software.amazon.lambda.powertools.logging.internal.JsonSerializer;

/**
* See {@link StructuredArguments#json(String, String)}
*/
public class JsonArgument implements StructuredArgument {
class JsonArgument implements StructuredArgument {
private final String key;
private final String rawJson;

Expand All @@ -39,4 +40,5 @@ public void writeTo(JsonSerializer serializer) {
public String toString() {
return key + "=" + rawJson;
}

}
3 changes: 2 additions & 1 deletion ...ng/src/main/java/software/amazon/lambda/powertools/logging/argument/KeyValueArgument.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,12 +15,13 @@
package software.amazon.lambda.powertools.logging.argument;

import java.util.Objects;

import software.amazon.lambda.powertools.logging.internal.JsonSerializer;

/**
* See {@link StructuredArguments#entry(String, Object)}
*/
public class KeyValueArgument implements StructuredArgument {
class KeyValueArgument implements StructuredArgument {
private final String key;
private final Object value;

Expand Down
Loading
Loading