From d5e3ee549d6c696fef7a918620c7b50c15cd4b7b Mon Sep 17 00:00:00 2001 From: Alexey Soshin Date: Fri, 10 Nov 2023 13:25:11 +0000 Subject: [PATCH 01/11] Add support for POWERTOOLS_LOGGER_LOG_EVENT --- .../core/internal/EnvironmentVariables.java | 21 ++++++++++++++++ .../core/internal/LambdaHandlerProcessor.java | 7 ++++++ powertools-logging/pom.xml | 5 ++++ .../logging/internal/LambdaLoggingAspect.java | 12 +++++++++- .../internal/LambdaLoggingAspectTest.java | 24 +++++++++++++++++++ 5 files changed, 68 insertions(+), 1 deletion(-) create mode 100644 powertools-core/src/main/java/software/amazon/lambda/powertools/core/internal/EnvironmentVariables.java diff --git a/powertools-core/src/main/java/software/amazon/lambda/powertools/core/internal/EnvironmentVariables.java b/powertools-core/src/main/java/software/amazon/lambda/powertools/core/internal/EnvironmentVariables.java new file mode 100644 index 000000000..5ca0cb881 --- /dev/null +++ b/powertools-core/src/main/java/software/amazon/lambda/powertools/core/internal/EnvironmentVariables.java @@ -0,0 +1,21 @@ +/* + * Copyright 2023 Amazon.com, Inc. or its affiliates. + * Licensed under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * http://www.apache.org/licenses/LICENSE-2.0 + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + */ + +package software.amazon.lambda.powertools.core.internal; + +public final class EnvironmentVariables { + public static class LOGGER { + public final static String LOG_EVENT = "POWERTOOLS_LOGGER_LOG_EVENT"; + } +} diff --git a/powertools-core/src/main/java/software/amazon/lambda/powertools/core/internal/LambdaHandlerProcessor.java b/powertools-core/src/main/java/software/amazon/lambda/powertools/core/internal/LambdaHandlerProcessor.java index 91c93c3f3..d4e18dddc 100644 --- a/powertools-core/src/main/java/software/amazon/lambda/powertools/core/internal/LambdaHandlerProcessor.java +++ b/powertools-core/src/main/java/software/amazon/lambda/powertools/core/internal/LambdaHandlerProcessor.java @@ -47,6 +47,13 @@ public static boolean isHandlerMethod(final ProceedingJoinPoint pjp) { return placedOnRequestHandler(pjp) || placedOnStreamHandler(pjp); } + /** + * The class needs to implement RequestHandler interface + * The function needs to have exactly two arguments + * The second argument needs to be of type com.amazonaws.services.lambda.runtime.Context + * @param pjp + * @return + */ public static boolean placedOnRequestHandler(final ProceedingJoinPoint pjp) { return RequestHandler.class.isAssignableFrom(pjp.getSignature().getDeclaringType()) && pjp.getArgs().length == 2 diff --git a/powertools-logging/pom.xml b/powertools-logging/pom.xml index c31448e30..54305d20d 100644 --- a/powertools-logging/pom.xml +++ b/powertools-logging/pom.xml @@ -129,6 +129,11 @@ jsonassert test + + org.junit-pioneer + junit-pioneer + test + diff --git a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspect.java b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspect.java index 4a98735af..636df1a60 100644 --- a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspect.java +++ b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspect.java @@ -54,6 +54,7 @@ import org.aspectj.lang.annotation.Aspect; import org.aspectj.lang.annotation.DeclarePrecedence; import org.aspectj.lang.annotation.Pointcut; +import software.amazon.lambda.powertools.core.internal.EnvironmentVariables; import software.amazon.lambda.powertools.logging.Logging; import software.amazon.lambda.powertools.logging.LoggingUtils; @@ -65,6 +66,7 @@ public final class LambdaLoggingAspect { private static final String LOG_LEVEL = System.getenv("POWERTOOLS_LOG_LEVEL"); private static final String SAMPLING_RATE = System.getenv("POWERTOOLS_LOGGER_SAMPLE_RATE"); + private static final Boolean LOG_EVENT; private static Level LEVEL_AT_INITIALISATION; @@ -74,6 +76,12 @@ public final class LambdaLoggingAspect { } LEVEL_AT_INITIALISATION = LOG.getLevel(); + + if (System.getenv(EnvironmentVariables.LOGGER.LOG_EVENT) != null) { + LOG_EVENT = Boolean.parseBoolean(System.getenv(EnvironmentVariables.LOGGER.LOG_EVENT)); + } else { + LOG_EVENT = false; + } } private static void resetLogLevels(Level logLevel) { @@ -104,7 +112,9 @@ public Object around(ProceedingJoinPoint pjp, getXrayTraceId().ifPresent(xRayTraceId -> appendKey("xray_trace_id", xRayTraceId)); - if (logging.logEvent()) { + // Make sure that the environment variable was enabled explicitly + // And that the handler was annotated with @Logging(logEvent = true) + if (LOG_EVENT && logging.logEvent()) { proceedArgs = logEvent(pjp); } diff --git a/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspectTest.java b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspectTest.java index 6952fe755..dbde3ad02 100644 --- a/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspectTest.java +++ b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspectTest.java @@ -58,8 +58,10 @@ import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; import org.junit.jupiter.params.ParameterizedTest; +import org.junitpioneer.jupiter.SetEnvironmentVariable; import org.mockito.Mock; import org.mockito.MockedStatic; +import software.amazon.lambda.powertools.core.internal.EnvironmentVariables; import software.amazon.lambda.powertools.core.internal.LambdaHandlerProcessor; import software.amazon.lambda.powertools.core.internal.SystemWrapper; import software.amazon.lambda.powertools.logging.handlers.PowerLogToolApiGatewayHttpApiCorrelationId; @@ -178,6 +180,7 @@ void shouldHaveNoEffectIfNotUsedOnLambdaHandler() { } @Test + @SetEnvironmentVariable(key = EnvironmentVariables.LOGGER.LOG_EVENT, value = "true") void shouldLogEventForHandler() throws IOException, JSONException { requestHandler = new PowerToolLogEventEnabled(); S3EventNotification s3EventNotification = s3EventNotification(); @@ -196,6 +199,26 @@ void shouldLogEventForHandler() throws IOException, JSONException { } @Test + @SetEnvironmentVariable(key = EnvironmentVariables.LOGGER.LOG_EVENT, value = "false") + void shouldNotLogEventForHandlerWhenEnvVariableSetToFalse() throws IOException, JSONException { + requestHandler = new PowerToolLogEventEnabled(); + S3EventNotification s3EventNotification = s3EventNotification(); + + requestHandler.handleRequest(s3EventNotification, context); + + Map log = parseToMap(Files.lines(Paths.get("target/logfile.json")).collect(joining())); + + String event = (String) log.get("message"); + + String expectEvent = new BufferedReader( + new InputStreamReader(this.getClass().getResourceAsStream("/s3EventNotification.json"))) + .lines().collect(joining("\n")); + + assertEquals(expectEvent, event, false); + } + + @Test + @SetEnvironmentVariable(key = EnvironmentVariables.LOGGER.LOG_EVENT, value = "true") void shouldLogEventForHandlerWithOverriddenObjectMapper() throws IOException, JSONException { RequestHandler handler = new PowerToolLogEventEnabledWithCustomMapper(); S3EventNotification s3EventNotification = s3EventNotification(); @@ -214,6 +237,7 @@ void shouldLogEventForHandlerWithOverriddenObjectMapper() throws IOException, JS } @Test + @SetEnvironmentVariable(key = EnvironmentVariables.LOGGER.LOG_EVENT, value = "true") void shouldLogEventForStreamAndLambdaStreamIsValid() throws IOException, JSONException { requestStreamHandler = new PowerToolLogEventEnabledForStream(); ByteArrayOutputStream output = new ByteArrayOutputStream(); From d9b44ba21d855d8bdf9657e8c3e5747bcebb60b5 Mon Sep 17 00:00:00 2001 From: Alexey Soshin Date: Fri, 10 Nov 2023 13:35:43 +0000 Subject: [PATCH 02/11] Update documentation with POWERTOOLS_LOGGER_LOG_EVENT --- docs/core/logging.md | 30 ++++++++++++++++-------------- docs/index.md | 18 ++++++++++-------- 2 files changed, 26 insertions(+), 22 deletions(-) diff --git a/docs/core/logging.md b/docs/core/logging.md index 2df9a4529..e16fa221a 100644 --- a/docs/core/logging.md +++ b/docs/core/logging.md @@ -200,20 +200,20 @@ You can also explicitly set a service name via **`POWERTOOLS_SERVICE_NAME`** env Your logs will always include the following keys to your structured logging: -Key | Type | Example | Description -------------------------------------------------- | ------------------------------------------------- | --------------------------------------------------------------------------------- | ------------------------------------------------- -**timestamp** | String | "2020-05-24 18:17:33,774" | Timestamp of actual log statement -**level** | String | "INFO" | Logging level -**coldStart** | Boolean | true| ColdStart value. -**service** | String | "payment" | Service name defined. "service_undefined" will be used if unknown -**samplingRate** | int | 0.1 | Debug logging sampling rate in percentage e.g. 10% in this case -**message** | String | "Collecting payment" | Log statement value. Unserializable JSON values will be casted to string -**functionName**| String | "example-powertools-HelloWorldFunction-1P1Z6B39FLU73" -**functionVersion**| String | "12" -**functionMemorySize**| String | "128" -**functionArn**| String | "arn:aws:lambda:eu-west-1:012345678910:function:example-powertools-HelloWorldFunction-1P1Z6B39FLU73" -**xray_trace_id**| String | "1-5759e988-bd862e3fe1be46a994272793" | X-Ray Trace ID when Lambda function has enabled Tracing -**function_request_id**| String | "899856cb-83d1-40d7-8611-9e78f15f32f4"" | AWS Request ID from lambda context +| Key | Type | Example | Description | +|-------------------------|---------|------------------------------------------------------------------------------------------------------|--------------------------------------------------------------------------| +| **timestamp** | String | "2020-05-24 18:17:33,774" | Timestamp of actual log statement | +| **level** | String | "INFO" | Logging level | +| **coldStart** | Boolean | true | ColdStart value. | +| **service** | String | "payment" | Service name defined. "service_undefined" will be used if unknown | +| **samplingRate** | int | 0.1 | Debug logging sampling rate in percentage e.g. 10% in this case | +| **message** | String | "Collecting payment" | Log statement value. Unserializable JSON values will be casted to string | +| **functionName** | String | "example-powertools-HelloWorldFunction-1P1Z6B39FLU73" | | +| **functionVersion** | String | "12" | | +| **functionMemorySize** | String | "128" | | +| **functionArn** | String | "arn:aws:lambda:eu-west-1:012345678910:function:example-powertools-HelloWorldFunction-1P1Z6B39FLU73" | | +| **xray_trace_id** | String | "1-5759e988-bd862e3fe1be46a994272793" | X-Ray Trace ID when Lambda function has enabled Tracing | +| **function_request_id** | String | "899856cb-83d1-40d7-8611-9e78f15f32f4"" | AWS Request ID from lambda context | ## Capturing context Lambda info @@ -221,6 +221,8 @@ You can enrich your structured logs with key Lambda context information via `log You can also explicitly log any incoming event using `logEvent` param. Refer [Override default object mapper](#override-default-object-mapper) to customise what is logged. +Note that the `logEvent` will work only if `POWERTOOLS_LOGGER_SAMPLE_RATE` environment variable is set to `"true"` + !!! warning Log event is disabled by default to prevent sensitive info being logged. diff --git a/docs/index.md b/docs/index.md index 6af4c5e8d..8d873ca9e 100644 --- a/docs/index.md +++ b/docs/index.md @@ -279,11 +279,13 @@ Depending on your version of Java (either Java 1.8 or 11+), the configuration sl !!! info **Explicit parameters take precedence over environment variables.** -| Environment variable | Description | Utility | -| ------------------------------------------------- | --------------------------------------------------------------------------------- | --------------------------------------------------------------------------------- | -| **POWERTOOLS_SERVICE_NAME** | Sets service name used for tracing namespace, metrics dimension and structured logging | All | -| **POWERTOOLS_METRICS_NAMESPACE** | Sets namespace used for metrics | [Metrics](./core/metrics) | -| **POWERTOOLS_LOGGER_SAMPLE_RATE** | Debug log sampling | [Logging](./core/logging) | -| **POWERTOOLS_LOG_LEVEL** | Sets logging level | [Logging](./core/logging) | -| **POWERTOOLS_TRACER_CAPTURE_RESPONSE** | Enables/Disables tracing mode to capture method response | [Tracing](./core/tracing) | -| **POWERTOOLS_TRACER_CAPTURE_ERROR** | Enables/Disables tracing mode to capture method error | [Tracing](./core/tracing) | +| Environment variable | Description | Utility | +|----------------------------------------|----------------------------------------------------------------------------------------|---------------------------| +| **POWERTOOLS_SERVICE_NAME** | Sets service name used for tracing namespace, metrics dimension and structured logging | All | +| **POWERTOOLS_METRICS_NAMESPACE** | Sets namespace used for metrics | [Metrics](./core/metrics) | +| **POWERTOOLS_LOGGER_SAMPLE_RATE** | Debug log sampling | [Logging](./core/logging) | +| **POWERTOOLS_LOG_LEVEL** | Sets logging level | [Logging](./core/logging) | +| **POWERTOOLS_LOGGER_LOG_EVENT** | Enables/Disables whether to log the incoming event when using the aspect | [Logging](./core/logging) | +| **POWERTOOLS_TRACER_CAPTURE_RESPONSE** | Enables/Disables tracing mode to capture method response | [Tracing](./core/tracing) | +| **POWERTOOLS_TRACER_CAPTURE_ERROR** | Enables/Disables tracing mode to capture method error | [Tracing](./core/tracing) | + From 3f6a4774c07d1bdce0f544a9eb254a791b92371e Mon Sep 17 00:00:00 2001 From: Alexey Soshin Date: Fri, 10 Nov 2023 16:09:40 +0000 Subject: [PATCH 03/11] Set POWERTOOLS_LOGGER_LOG_EVENT in the intergration tests --- powertools-test-suite/pom.xml | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/powertools-test-suite/pom.xml b/powertools-test-suite/pom.xml index 34e80b06e..3d1657033 100644 --- a/powertools-test-suite/pom.xml +++ b/powertools-test-suite/pom.xml @@ -119,6 +119,15 @@ + + org.apache.maven.plugins + maven-surefire-plugin + + + true + + + dev.aspectj aspectj-maven-plugin From 288b6764c93e0a94dc44bd6041beb830ba11e05d Mon Sep 17 00:00:00 2001 From: Alexey Soshin Date: Fri, 10 Nov 2023 16:53:15 +0000 Subject: [PATCH 04/11] Validate that the log file is not being written --- powertools-logging/pom.xml | 5 - .../logging/internal/LambdaLoggingAspect.java | 2 +- .../internal/LambdaLoggingAspectTest.java | 92 ++++++++----------- 3 files changed, 37 insertions(+), 62 deletions(-) diff --git a/powertools-logging/pom.xml b/powertools-logging/pom.xml index 54305d20d..c31448e30 100644 --- a/powertools-logging/pom.xml +++ b/powertools-logging/pom.xml @@ -129,11 +129,6 @@ jsonassert test - - org.junit-pioneer - junit-pioneer - test - diff --git a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspect.java b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspect.java index 636df1a60..e24eb4a61 100644 --- a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspect.java +++ b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspect.java @@ -66,7 +66,7 @@ public final class LambdaLoggingAspect { private static final String LOG_LEVEL = System.getenv("POWERTOOLS_LOG_LEVEL"); private static final String SAMPLING_RATE = System.getenv("POWERTOOLS_LOGGER_SAMPLE_RATE"); - private static final Boolean LOG_EVENT; + private static Boolean LOG_EVENT; private static Level LEVEL_AT_INITIALISATION; diff --git a/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspectTest.java b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspectTest.java index dbde3ad02..abfd8ed75 100644 --- a/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspectTest.java +++ b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspectTest.java @@ -14,19 +14,6 @@ package software.amazon.lambda.powertools.logging.internal; -import static java.util.Collections.emptyMap; -import static java.util.Collections.singletonList; -import static java.util.stream.Collectors.joining; -import static org.apache.commons.lang3.reflect.FieldUtils.writeStaticField; -import static org.assertj.core.api.Assertions.assertThat; -import static org.assertj.core.api.Assertions.fail; -import static org.mockito.Mockito.mockStatic; -import static org.mockito.Mockito.when; -import static org.mockito.MockitoAnnotations.openMocks; -import static org.skyscreamer.jsonassert.JSONAssert.assertEquals; -import static software.amazon.lambda.powertools.core.internal.SystemWrapper.getProperty; -import static software.amazon.lambda.powertools.core.internal.SystemWrapper.getenv; - import com.amazonaws.services.lambda.runtime.Context; import com.amazonaws.services.lambda.runtime.RequestHandler; import com.amazonaws.services.lambda.runtime.RequestStreamHandler; @@ -37,45 +24,42 @@ import com.amazonaws.services.lambda.runtime.tests.annotations.Event; import com.fasterxml.jackson.core.JsonProcessingException; import com.fasterxml.jackson.databind.ObjectMapper; -import java.io.BufferedReader; -import java.io.ByteArrayInputStream; -import java.io.ByteArrayOutputStream; -import java.io.IOException; -import java.io.InputStreamReader; -import java.lang.reflect.InvocationTargetException; -import java.lang.reflect.Method; -import java.nio.channels.FileChannel; -import java.nio.charset.StandardCharsets; -import java.nio.file.Files; -import java.nio.file.Paths; -import java.nio.file.StandardOpenOption; -import java.util.List; -import java.util.Map; -import java.util.stream.Collectors; import org.apache.logging.log4j.Level; import org.apache.logging.log4j.ThreadContext; import org.json.JSONException; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; import org.junit.jupiter.params.ParameterizedTest; -import org.junitpioneer.jupiter.SetEnvironmentVariable; import org.mockito.Mock; import org.mockito.MockedStatic; -import software.amazon.lambda.powertools.core.internal.EnvironmentVariables; import software.amazon.lambda.powertools.core.internal.LambdaHandlerProcessor; import software.amazon.lambda.powertools.core.internal.SystemWrapper; -import software.amazon.lambda.powertools.logging.handlers.PowerLogToolApiGatewayHttpApiCorrelationId; -import software.amazon.lambda.powertools.logging.handlers.PowerLogToolApiGatewayRestApiCorrelationId; -import software.amazon.lambda.powertools.logging.handlers.PowerLogToolEnabled; -import software.amazon.lambda.powertools.logging.handlers.PowerLogToolEnabledForStream; -import software.amazon.lambda.powertools.logging.handlers.PowerToolDisabled; -import software.amazon.lambda.powertools.logging.handlers.PowerToolDisabledForStream; -import software.amazon.lambda.powertools.logging.handlers.PowerToolLogEventEnabled; -import software.amazon.lambda.powertools.logging.handlers.PowerToolLogEventEnabledForStream; -import software.amazon.lambda.powertools.logging.handlers.PowerToolLogEventEnabledWithCustomMapper; -import software.amazon.lambda.powertools.logging.handlers.PowertoolsLogAlbCorrelationId; -import software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEnabledWithClearState; -import software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEventBridgeCorrelationId; +import software.amazon.lambda.powertools.logging.handlers.*; + +import java.io.*; +import java.lang.reflect.InvocationTargetException; +import java.lang.reflect.Method; +import java.nio.channels.FileChannel; +import java.nio.charset.StandardCharsets; +import java.nio.file.Files; +import java.nio.file.Paths; +import java.nio.file.StandardOpenOption; +import java.util.List; +import java.util.Map; +import java.util.stream.Collectors; + +import static java.util.Collections.emptyMap; +import static java.util.Collections.singletonList; +import static java.util.stream.Collectors.joining; +import static org.apache.commons.lang3.reflect.FieldUtils.writeStaticField; +import static org.assertj.core.api.Assertions.assertThat; +import static org.assertj.core.api.Assertions.fail; +import static org.mockito.Mockito.mockStatic; +import static org.mockito.Mockito.when; +import static org.mockito.MockitoAnnotations.openMocks; +import static org.skyscreamer.jsonassert.JSONAssert.assertEquals; +import static software.amazon.lambda.powertools.core.internal.SystemWrapper.getProperty; +import static software.amazon.lambda.powertools.core.internal.SystemWrapper.getenv; class LambdaLoggingAspectTest { @@ -91,6 +75,7 @@ void setUp() throws IllegalAccessException, IOException, NoSuchMethodException, openMocks(this); ThreadContext.clearAll(); writeStaticField(LambdaHandlerProcessor.class, "IS_COLD_START", null, true); + writeStaticField(LambdaLoggingAspect.class, "LOG_EVENT", Boolean.TRUE, true); setupContext(); requestHandler = new PowerLogToolEnabled(); requestStreamHandler = new PowerLogToolEnabledForStream(); @@ -180,7 +165,6 @@ void shouldHaveNoEffectIfNotUsedOnLambdaHandler() { } @Test - @SetEnvironmentVariable(key = EnvironmentVariables.LOGGER.LOG_EVENT, value = "true") void shouldLogEventForHandler() throws IOException, JSONException { requestHandler = new PowerToolLogEventEnabled(); S3EventNotification s3EventNotification = s3EventNotification(); @@ -198,27 +182,24 @@ void shouldLogEventForHandler() throws IOException, JSONException { assertEquals(expectEvent, event, false); } + /** + * If POWERTOOLS_LOGGER_LOG_EVENT was set to false, the handler should log anything, despite @Logging(logEvent=true) + * @throws IOException + */ @Test - @SetEnvironmentVariable(key = EnvironmentVariables.LOGGER.LOG_EVENT, value = "false") - void shouldNotLogEventForHandlerWhenEnvVariableSetToFalse() throws IOException, JSONException { + void shouldNotLogEventForHandlerWhenEnvVariableSetToFalse() throws IOException, IllegalAccessException { + writeStaticField(LambdaLoggingAspect.class, "LOG_EVENT", Boolean.FALSE, true); + requestHandler = new PowerToolLogEventEnabled(); S3EventNotification s3EventNotification = s3EventNotification(); requestHandler.handleRequest(s3EventNotification, context); - Map log = parseToMap(Files.lines(Paths.get("target/logfile.json")).collect(joining())); - - String event = (String) log.get("message"); - - String expectEvent = new BufferedReader( - new InputStreamReader(this.getClass().getResourceAsStream("/s3EventNotification.json"))) - .lines().collect(joining("\n")); - - assertEquals(expectEvent, event, false); + String s = Files.lines(Paths.get("target/logfile.json")).collect(joining()); + assertThat(s).isEmpty(); } @Test - @SetEnvironmentVariable(key = EnvironmentVariables.LOGGER.LOG_EVENT, value = "true") void shouldLogEventForHandlerWithOverriddenObjectMapper() throws IOException, JSONException { RequestHandler handler = new PowerToolLogEventEnabledWithCustomMapper(); S3EventNotification s3EventNotification = s3EventNotification(); @@ -237,7 +218,6 @@ void shouldLogEventForHandlerWithOverriddenObjectMapper() throws IOException, JS } @Test - @SetEnvironmentVariable(key = EnvironmentVariables.LOGGER.LOG_EVENT, value = "true") void shouldLogEventForStreamAndLambdaStreamIsValid() throws IOException, JSONException { requestStreamHandler = new PowerToolLogEventEnabledForStream(); ByteArrayOutputStream output = new ByteArrayOutputStream(); From da1c37ce9d149537f512e0246954b9f3d7f45e63 Mon Sep 17 00:00:00 2001 From: Alexey Soshin Date: Mon, 13 Nov 2023 09:43:59 +0000 Subject: [PATCH 05/11] Change the behaviour of POWERTOOLS_LOGGER_LOG_EVENT to force-enable logging for endpoints, even if the annotation doesn't specify it --- .../logging/internal/LambdaLoggingAspect.java | 6 +-- .../handlers/PowerToolLogEventDisabled.java | 28 +++++++++++ .../internal/LambdaLoggingAspectTest.java | 49 +++++++++++++++---- 3 files changed, 70 insertions(+), 13 deletions(-) create mode 100644 powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/handlers/PowerToolLogEventDisabled.java diff --git a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspect.java b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspect.java index e24eb4a61..4970c6342 100644 --- a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspect.java +++ b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspect.java @@ -112,9 +112,9 @@ public Object around(ProceedingJoinPoint pjp, getXrayTraceId().ifPresent(xRayTraceId -> appendKey("xray_trace_id", xRayTraceId)); - // Make sure that the environment variable was enabled explicitly - // And that the handler was annotated with @Logging(logEvent = true) - if (LOG_EVENT && logging.logEvent()) { + // Check that the environment variable was enabled explicitly + // Or that the handler was annotated with @Logging(logEvent = true) + if (LOG_EVENT || logging.logEvent()) { proceedArgs = logEvent(pjp); } diff --git a/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/handlers/PowerToolLogEventDisabled.java b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/handlers/PowerToolLogEventDisabled.java new file mode 100644 index 000000000..77103e450 --- /dev/null +++ b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/handlers/PowerToolLogEventDisabled.java @@ -0,0 +1,28 @@ +/* + * Copyright 2023 Amazon.com, Inc. or its affiliates. + * Licensed under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * http://www.apache.org/licenses/LICENSE-2.0 + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + */ + +package software.amazon.lambda.powertools.logging.handlers; + +import com.amazonaws.services.lambda.runtime.Context; +import com.amazonaws.services.lambda.runtime.RequestHandler; +import software.amazon.lambda.powertools.logging.Logging; + +public class PowerToolLogEventDisabled implements RequestHandler { + + @Logging(logEvent = false) + @Override + public Object handleRequest(Object input, Context context) { + return null; + } +} diff --git a/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspectTest.java b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspectTest.java index abfd8ed75..75cf22aa5 100644 --- a/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspectTest.java +++ b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspectTest.java @@ -27,6 +27,7 @@ import org.apache.logging.log4j.Level; import org.apache.logging.log4j.ThreadContext; import org.json.JSONException; +import org.junit.jupiter.api.Assertions; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; import org.junit.jupiter.params.ParameterizedTest; @@ -54,6 +55,7 @@ import static org.apache.commons.lang3.reflect.FieldUtils.writeStaticField; import static org.assertj.core.api.Assertions.assertThat; import static org.assertj.core.api.Assertions.fail; +import static org.junit.jupiter.api.Assertions.assertTrue; import static org.mockito.Mockito.mockStatic; import static org.mockito.Mockito.when; import static org.mockito.MockitoAnnotations.openMocks; @@ -75,7 +77,6 @@ void setUp() throws IllegalAccessException, IOException, NoSuchMethodException, openMocks(this); ThreadContext.clearAll(); writeStaticField(LambdaHandlerProcessor.class, "IS_COLD_START", null, true); - writeStaticField(LambdaLoggingAspect.class, "LOG_EVENT", Boolean.TRUE, true); setupContext(); requestHandler = new PowerLogToolEnabled(); requestStreamHandler = new PowerLogToolEnabledForStream(); @@ -103,7 +104,7 @@ void shouldSetLambdaContextWhenEnabled() { void shouldSetLambdaContextForStreamHandlerWhenEnabled() throws IOException { requestStreamHandler = new PowerLogToolEnabledForStream(); - requestStreamHandler.handleRequest(new ByteArrayInputStream(new byte[] {}), new ByteArrayOutputStream(), + requestStreamHandler.handleRequest(new ByteArrayInputStream(new byte[]{}), new ByteArrayOutputStream(), context); assertThat(ThreadContext.getImmutableContext()) @@ -119,14 +120,14 @@ void shouldSetLambdaContextForStreamHandlerWhenEnabled() throws IOException { @Test void shouldSetColdStartFlag() throws IOException { - requestStreamHandler.handleRequest(new ByteArrayInputStream(new byte[] {}), new ByteArrayOutputStream(), + requestStreamHandler.handleRequest(new ByteArrayInputStream(new byte[]{}), new ByteArrayOutputStream(), context); assertThat(ThreadContext.getImmutableContext()) .hasSize(EXPECTED_CONTEXT_SIZE) .containsEntry("coldStart", "true"); - requestStreamHandler.handleRequest(new ByteArrayInputStream(new byte[] {}), new ByteArrayOutputStream(), + requestStreamHandler.handleRequest(new ByteArrayInputStream(new byte[]{}), new ByteArrayOutputStream(), context); assertThat(ThreadContext.getImmutableContext()) @@ -183,20 +184,48 @@ void shouldLogEventForHandler() throws IOException, JSONException { } /** - * If POWERTOOLS_LOGGER_LOG_EVENT was set to false, the handler should log anything, despite @Logging(logEvent=true) + * If POWERTOOLS_LOGGER_LOG_EVENT was set to true, the handler should log, despite @Logging(logEvent=false) + * * @throws IOException */ @Test - void shouldNotLogEventForHandlerWhenEnvVariableSetToFalse() throws IOException, IllegalAccessException { - writeStaticField(LambdaLoggingAspect.class, "LOG_EVENT", Boolean.FALSE, true); + void shouldLogEventForHandlerWhenEnvVariableSetToTrue() throws IOException, IllegalAccessException, JSONException { + try { + writeStaticField(LambdaLoggingAspect.class, "LOG_EVENT", Boolean.TRUE, true); - requestHandler = new PowerToolLogEventEnabled(); + requestHandler = new PowerToolLogEventDisabled(); + S3EventNotification s3EventNotification = s3EventNotification(); + + requestHandler.handleRequest(s3EventNotification, context); + + Map log = parseToMap(Files.lines(Paths.get("target/logfile.json")).collect(joining())); + + String event = (String) log.get("message"); + + String expectEvent = new BufferedReader( + new InputStreamReader(this.getClass().getResourceAsStream("/s3EventNotification.json"))) + .lines().collect(joining("\n")); + + assertEquals(expectEvent, event, false); + } finally { + writeStaticField(LambdaLoggingAspect.class, "LOG_EVENT", Boolean.FALSE, true); + } + } + + /** + * If POWERTOOLS_LOGGER_LOG_EVENT was set to false and @Logging(logEvent=false), the handler shouldn't log + * + * @throws IOException + */ + @Test + void shouldNotLogEventForHandlerWhenEnvVariableSetToFalse() throws IOException { + requestHandler = new PowerToolLogEventDisabled(); S3EventNotification s3EventNotification = s3EventNotification(); requestHandler.handleRequest(s3EventNotification, context); - String s = Files.lines(Paths.get("target/logfile.json")).collect(joining()); - assertThat(s).isEmpty(); + Assertions.assertEquals(0, + Files.lines(Paths.get("target/logfile.json")).collect(joining()).length()); } @Test From 03094f15d3594271d627984e79be84d1513cdaca Mon Sep 17 00:00:00 2001 From: Alexey Soshin Date: Mon, 13 Nov 2023 09:45:57 +0000 Subject: [PATCH 06/11] Remove EnvironmentVariables, to simplify v2 migration --- .../core/internal/EnvironmentVariables.java | 21 ------------------- .../logging/internal/LambdaLoggingAspect.java | 8 ++++--- 2 files changed, 5 insertions(+), 24 deletions(-) delete mode 100644 powertools-core/src/main/java/software/amazon/lambda/powertools/core/internal/EnvironmentVariables.java diff --git a/powertools-core/src/main/java/software/amazon/lambda/powertools/core/internal/EnvironmentVariables.java b/powertools-core/src/main/java/software/amazon/lambda/powertools/core/internal/EnvironmentVariables.java deleted file mode 100644 index 5ca0cb881..000000000 --- a/powertools-core/src/main/java/software/amazon/lambda/powertools/core/internal/EnvironmentVariables.java +++ /dev/null @@ -1,21 +0,0 @@ -/* - * Copyright 2023 Amazon.com, Inc. or its affiliates. - * Licensed under the Apache License, Version 2.0 (the - * "License"); you may not use this file except in compliance - * with the License. You may obtain a copy of the License at - * http://www.apache.org/licenses/LICENSE-2.0 - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - * - */ - -package software.amazon.lambda.powertools.core.internal; - -public final class EnvironmentVariables { - public static class LOGGER { - public final static String LOG_EVENT = "POWERTOOLS_LOGGER_LOG_EVENT"; - } -} diff --git a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspect.java b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspect.java index 4970c6342..ff556d89a 100644 --- a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspect.java +++ b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LambdaLoggingAspect.java @@ -33,6 +33,7 @@ import com.fasterxml.jackson.core.JsonPointer; import com.fasterxml.jackson.core.JsonProcessingException; import com.fasterxml.jackson.databind.JsonNode; + import java.io.ByteArrayInputStream; import java.io.ByteArrayOutputStream; import java.io.IOException; @@ -42,6 +43,7 @@ import java.util.Map; import java.util.Optional; import java.util.Random; + import org.apache.logging.log4j.Level; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; @@ -54,7 +56,6 @@ import org.aspectj.lang.annotation.Aspect; import org.aspectj.lang.annotation.DeclarePrecedence; import org.aspectj.lang.annotation.Pointcut; -import software.amazon.lambda.powertools.core.internal.EnvironmentVariables; import software.amazon.lambda.powertools.logging.Logging; import software.amazon.lambda.powertools.logging.LoggingUtils; @@ -77,8 +78,9 @@ public final class LambdaLoggingAspect { LEVEL_AT_INITIALISATION = LOG.getLevel(); - if (System.getenv(EnvironmentVariables.LOGGER.LOG_EVENT) != null) { - LOG_EVENT = Boolean.parseBoolean(System.getenv(EnvironmentVariables.LOGGER.LOG_EVENT)); + String logEvent = System.getenv("POWERTOOLS_LOGGER_LOG_EVENT"); + if (logEvent != null) { + LOG_EVENT = Boolean.parseBoolean(logEvent); } else { LOG_EVENT = false; } From 6a53b4c6e2860c8e7cf55c39921fc6aa2ea23191 Mon Sep 17 00:00:00 2001 From: Alexey Soshin Date: Mon, 13 Nov 2023 09:49:39 +0000 Subject: [PATCH 07/11] Remove formatting and change documentation --- docs/core/logging.md | 30 +++++++++++++++--------------- 1 file changed, 15 insertions(+), 15 deletions(-) diff --git a/docs/core/logging.md b/docs/core/logging.md index e16fa221a..5c09112ea 100644 --- a/docs/core/logging.md +++ b/docs/core/logging.md @@ -200,20 +200,20 @@ You can also explicitly set a service name via **`POWERTOOLS_SERVICE_NAME`** env Your logs will always include the following keys to your structured logging: -| Key | Type | Example | Description | -|-------------------------|---------|------------------------------------------------------------------------------------------------------|--------------------------------------------------------------------------| -| **timestamp** | String | "2020-05-24 18:17:33,774" | Timestamp of actual log statement | -| **level** | String | "INFO" | Logging level | -| **coldStart** | Boolean | true | ColdStart value. | -| **service** | String | "payment" | Service name defined. "service_undefined" will be used if unknown | -| **samplingRate** | int | 0.1 | Debug logging sampling rate in percentage e.g. 10% in this case | -| **message** | String | "Collecting payment" | Log statement value. Unserializable JSON values will be casted to string | -| **functionName** | String | "example-powertools-HelloWorldFunction-1P1Z6B39FLU73" | | -| **functionVersion** | String | "12" | | -| **functionMemorySize** | String | "128" | | -| **functionArn** | String | "arn:aws:lambda:eu-west-1:012345678910:function:example-powertools-HelloWorldFunction-1P1Z6B39FLU73" | | -| **xray_trace_id** | String | "1-5759e988-bd862e3fe1be46a994272793" | X-Ray Trace ID when Lambda function has enabled Tracing | -| **function_request_id** | String | "899856cb-83d1-40d7-8611-9e78f15f32f4"" | AWS Request ID from lambda context | +Key | Type | Example | Description +------------------------------------------------- | ------------------------------------------------- | --------------------------------------------------------------------------------- | ------------------------------------------------- +**timestamp** | String | "2020-05-24 18:17:33,774" | Timestamp of actual log statement +**level** | String | "INFO" | Logging level +**coldStart** | Boolean | true| ColdStart value. +**service** | String | "payment" | Service name defined. "service_undefined" will be used if unknown +**samplingRate** | int | 0.1 | Debug logging sampling rate in percentage e.g. 10% in this case +**message** | String | "Collecting payment" | Log statement value. Unserializable JSON values will be casted to string +**functionName**| String | "example-powertools-HelloWorldFunction-1P1Z6B39FLU73" +**functionVersion**| String | "12" +**functionMemorySize**| String | "128" +**functionArn**| String | "arn:aws:lambda:eu-west-1:012345678910:function:example-powertools-HelloWorldFunction-1P1Z6B39FLU73" +**xray_trace_id**| String | "1-5759e988-bd862e3fe1be46a994272793" | X-Ray Trace ID when Lambda function has enabled Tracing +**function_request_id**| String | "899856cb-83d1-40d7-8611-9e78f15f32f4"" | AWS Request ID from lambda context ## Capturing context Lambda info @@ -221,7 +221,7 @@ You can enrich your structured logs with key Lambda context information via `log You can also explicitly log any incoming event using `logEvent` param. Refer [Override default object mapper](#override-default-object-mapper) to customise what is logged. -Note that the `logEvent` will work only if `POWERTOOLS_LOGGER_SAMPLE_RATE` environment variable is set to `"true"` +If you want to enable this event logging for all handlers, set `POWERTOOLS_LOGGER_SAMPLE_RATE` environment variable to `"true"` !!! warning Log event is disabled by default to prevent sensitive info being logged. From 5df3b3b3c86ba704dd7b3de5b9a7c82b8f4276cf Mon Sep 17 00:00:00 2001 From: Alexey Soshin Date: Mon, 13 Nov 2023 09:51:22 +0000 Subject: [PATCH 08/11] Remove formatting --- docs/index.md | 18 +++++++++--------- 1 file changed, 9 insertions(+), 9 deletions(-) diff --git a/docs/index.md b/docs/index.md index 8d873ca9e..92589be7c 100644 --- a/docs/index.md +++ b/docs/index.md @@ -279,13 +279,13 @@ Depending on your version of Java (either Java 1.8 or 11+), the configuration sl !!! info **Explicit parameters take precedence over environment variables.** -| Environment variable | Description | Utility | -|----------------------------------------|----------------------------------------------------------------------------------------|---------------------------| -| **POWERTOOLS_SERVICE_NAME** | Sets service name used for tracing namespace, metrics dimension and structured logging | All | -| **POWERTOOLS_METRICS_NAMESPACE** | Sets namespace used for metrics | [Metrics](./core/metrics) | -| **POWERTOOLS_LOGGER_SAMPLE_RATE** | Debug log sampling | [Logging](./core/logging) | -| **POWERTOOLS_LOG_LEVEL** | Sets logging level | [Logging](./core/logging) | -| **POWERTOOLS_LOGGER_LOG_EVENT** | Enables/Disables whether to log the incoming event when using the aspect | [Logging](./core/logging) | -| **POWERTOOLS_TRACER_CAPTURE_RESPONSE** | Enables/Disables tracing mode to capture method response | [Tracing](./core/tracing) | -| **POWERTOOLS_TRACER_CAPTURE_ERROR** | Enables/Disables tracing mode to capture method error | [Tracing](./core/tracing) | +| Environment variable | Description | Utility | +| ------------------------------------------------- | --------------------------------------------------------------------------------- | --------------------------------------------------------------------------------- | +| **POWERTOOLS_SERVICE_NAME** | Sets service name used for tracing namespace, metrics dimension and structured logging | All | +| **POWERTOOLS_METRICS_NAMESPACE** | Sets namespace used for metrics | [Metrics](./core/metrics) | +| **POWERTOOLS_LOGGER_SAMPLE_RATE** | Debug log sampling | [Logging](./core/logging) | +| **POWERTOOLS_LOG_LEVEL** | Sets logging level | [Logging](./core/logging) | +| **POWERTOOLS_LOGGER_LOG_EVENT** | Enables/Disables whether to log the incoming event when using the aspect | [Logging](./core/logging) | +| **POWERTOOLS_TRACER_CAPTURE_RESPONSE** | Enables/Disables tracing mode to capture method response | [Tracing](./core/tracing) | +| **POWERTOOLS_TRACER_CAPTURE_ERROR** | Enables/Disables tracing mode to capture method error | [Tracing](./core/tracing) | From d990ef81a7c0085d8217b3dfbbfd365f952a411f Mon Sep 17 00:00:00 2001 From: Alexey Soshin Date: Mon, 13 Nov 2023 09:53:44 +0000 Subject: [PATCH 09/11] Remove forceful logging of the events --- powertools-test-suite/pom.xml | 9 --------- 1 file changed, 9 deletions(-) diff --git a/powertools-test-suite/pom.xml b/powertools-test-suite/pom.xml index 3d1657033..34e80b06e 100644 --- a/powertools-test-suite/pom.xml +++ b/powertools-test-suite/pom.xml @@ -119,15 +119,6 @@ - - org.apache.maven.plugins - maven-surefire-plugin - - - true - - - dev.aspectj aspectj-maven-plugin From 3e3b4029393b98533d4d0fcda7ddaf300c6d788b Mon Sep 17 00:00:00 2001 From: Alexey Soshin Date: Mon, 13 Nov 2023 10:14:49 +0000 Subject: [PATCH 10/11] Update docs/core/logging.md --- docs/core/logging.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/docs/core/logging.md b/docs/core/logging.md index 5c09112ea..9a9ef0163 100644 --- a/docs/core/logging.md +++ b/docs/core/logging.md @@ -221,7 +221,7 @@ You can enrich your structured logs with key Lambda context information via `log You can also explicitly log any incoming event using `logEvent` param. Refer [Override default object mapper](#override-default-object-mapper) to customise what is logged. -If you want to enable this event logging for all handlers, set `POWERTOOLS_LOGGER_SAMPLE_RATE` environment variable to `"true"` +When debugging in non-production environments, you can instruct Logger to log the incoming event with `@Logger(logEvent = true)` or via `POWERTOOLS_LOGGER_LOG_EVENT=true` environment variable. !!! warning Log event is disabled by default to prevent sensitive info being logged. From 4645b621209d6a2c3a308ea27157204d543bc92e Mon Sep 17 00:00:00 2001 From: Alexey Soshin Date: Tue, 14 Nov 2023 10:36:25 +0000 Subject: [PATCH 11/11] Simplify documentation --- docs/core/logging.md | 4 ---- 1 file changed, 4 deletions(-) diff --git a/docs/core/logging.md b/docs/core/logging.md index 5c09112ea..9e81d45d4 100644 --- a/docs/core/logging.md +++ b/docs/core/logging.md @@ -217,10 +217,6 @@ Key | Type | Example | Description ## Capturing context Lambda info -You can enrich your structured logs with key Lambda context information via `logEvent` annotation parameter. -You can also explicitly log any incoming event using `logEvent` param. Refer [Override default object mapper](#override-default-object-mapper) -to customise what is logged. - If you want to enable this event logging for all handlers, set `POWERTOOLS_LOGGER_SAMPLE_RATE` environment variable to `"true"` !!! warning