diff --git a/examples/powertools-examples-kafka/src/main/java/org/demo/kafka/protobuf/ProtobufProduct.java b/examples/powertools-examples-kafka/src/main/java/org/demo/kafka/protobuf/ProtobufProduct.java index e36810e08..13d8905f2 100644 --- a/examples/powertools-examples-kafka/src/main/java/org/demo/kafka/protobuf/ProtobufProduct.java +++ b/examples/powertools-examples-kafka/src/main/java/org/demo/kafka/protobuf/ProtobufProduct.java @@ -1,7 +1,7 @@ // Generated by the protocol buffer compiler. DO NOT EDIT! // NO CHECKED-IN PROTOBUF GENCODE // source: ProtobufProduct.proto -// Protobuf Java Version: 4.32.1 +// Protobuf Java Version: 4.33.0 package org.demo.kafka.protobuf; @@ -18,10 +18,10 @@ public final class ProtobufProduct extends com.google.protobuf.RuntimeVersion.validateProtobufGencodeVersion( com.google.protobuf.RuntimeVersion.RuntimeDomain.PUBLIC, /* major= */ 4, - /* minor= */ 32, - /* patch= */ 1, + /* minor= */ 33, + /* patch= */ 0, /* suffix= */ "", - ProtobufProduct.class.getName()); + "ProtobufProduct"); } // Use ProtobufProduct.newBuilder() to construct. private ProtobufProduct(com.google.protobuf.GeneratedMessage.Builder builder) { diff --git a/examples/powertools-examples-kafka/src/main/java/org/demo/kafka/protobuf/ProtobufProductOrBuilder.java b/examples/powertools-examples-kafka/src/main/java/org/demo/kafka/protobuf/ProtobufProductOrBuilder.java index 951644b2f..ae7cb2182 100644 --- a/examples/powertools-examples-kafka/src/main/java/org/demo/kafka/protobuf/ProtobufProductOrBuilder.java +++ b/examples/powertools-examples-kafka/src/main/java/org/demo/kafka/protobuf/ProtobufProductOrBuilder.java @@ -1,7 +1,7 @@ // Generated by the protocol buffer compiler. DO NOT EDIT! // NO CHECKED-IN PROTOBUF GENCODE // source: ProtobufProduct.proto -// Protobuf Java Version: 4.32.1 +// Protobuf Java Version: 4.33.0 package org.demo.kafka.protobuf; diff --git a/examples/powertools-examples-kafka/src/main/java/org/demo/kafka/protobuf/ProtobufProductOuterClass.java b/examples/powertools-examples-kafka/src/main/java/org/demo/kafka/protobuf/ProtobufProductOuterClass.java index 0da2eec57..4fcac7bd7 100644 --- a/examples/powertools-examples-kafka/src/main/java/org/demo/kafka/protobuf/ProtobufProductOuterClass.java +++ b/examples/powertools-examples-kafka/src/main/java/org/demo/kafka/protobuf/ProtobufProductOuterClass.java @@ -1,7 +1,7 @@ // Generated by the protocol buffer compiler. DO NOT EDIT! // NO CHECKED-IN PROTOBUF GENCODE // source: ProtobufProduct.proto -// Protobuf Java Version: 4.32.1 +// Protobuf Java Version: 4.33.0 package org.demo.kafka.protobuf; @@ -12,10 +12,10 @@ private ProtobufProductOuterClass() {} com.google.protobuf.RuntimeVersion.validateProtobufGencodeVersion( com.google.protobuf.RuntimeVersion.RuntimeDomain.PUBLIC, /* major= */ 4, - /* minor= */ 32, - /* patch= */ 1, + /* minor= */ 33, + /* patch= */ 0, /* suffix= */ "", - ProtobufProductOuterClass.class.getName()); + "ProtobufProductOuterClass"); } public static void registerAllExtensions( com.google.protobuf.ExtensionRegistryLite registry) { @@ -51,7 +51,7 @@ public static void registerAllExtensions( new com.google.protobuf.Descriptors.FileDescriptor[] { }); internal_static_org_demo_kafka_protobuf_ProtobufProduct_descriptor = - getDescriptor().getMessageTypes().get(0); + getDescriptor().getMessageType(0); internal_static_org_demo_kafka_protobuf_ProtobufProduct_fieldAccessorTable = new com.google.protobuf.GeneratedMessage.FieldAccessorTable( internal_static_org_demo_kafka_protobuf_ProtobufProduct_descriptor, diff --git a/powertools-e2e-tests/handlers/logging-functional/pom.xml b/powertools-e2e-tests/handlers/logging-functional/pom.xml new file mode 100644 index 000000000..5d774fe21 --- /dev/null +++ b/powertools-e2e-tests/handlers/logging-functional/pom.xml @@ -0,0 +1,60 @@ + + 4.0.0 + + + software.amazon.lambda + e2e-test-handlers-parent + 2.5.0 + + + e2e-test-handler-logging-functional + jar + E2E test handler – Logging Functional + + + + software.amazon.lambda + powertools-logging-log4j + + + software.amazon.lambda + powertools-logging + + + com.amazonaws + aws-lambda-java-events + + + com.amazonaws + aws-lambda-java-runtime-interface-client + + + com.amazonaws + aws-lambda-java-core + + + + + + + org.apache.maven.plugins + maven-shade-plugin + + + + + + + native-image + + + + org.graalvm.buildtools + native-maven-plugin + + + + + + diff --git a/powertools-e2e-tests/handlers/logging-functional/src/main/java/software/amazon/lambda/powertools/e2e/Function.java b/powertools-e2e-tests/handlers/logging-functional/src/main/java/software/amazon/lambda/powertools/e2e/Function.java new file mode 100644 index 000000000..853239137 --- /dev/null +++ b/powertools-e2e-tests/handlers/logging-functional/src/main/java/software/amazon/lambda/powertools/e2e/Function.java @@ -0,0 +1,41 @@ +/* + * 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.e2e; + +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 software.amazon.lambda.powertools.logging.Logging; +import software.amazon.lambda.powertools.logging.PowertoolsLogging; + +public class Function implements RequestHandler { + private static final Logger LOG = LoggerFactory.getLogger(Function.class); + + public String handleRequest(Input input, Context context) { + PowertoolsLogging.initializeLogging(context); + + input.getKeys().forEach(MDC::put); + LOG.info(input.getMessage()); + + // Flush buffer manually since we buffer at INFO level to test log buffering + PowertoolsLogging.flushBuffer(); + + return "OK"; + } +} diff --git a/powertools-e2e-tests/handlers/logging-functional/src/main/java/software/amazon/lambda/powertools/e2e/Input.java b/powertools-e2e-tests/handlers/logging-functional/src/main/java/software/amazon/lambda/powertools/e2e/Input.java new file mode 100644 index 000000000..66fd49ddc --- /dev/null +++ b/powertools-e2e-tests/handlers/logging-functional/src/main/java/software/amazon/lambda/powertools/e2e/Input.java @@ -0,0 +1,38 @@ +/* + * 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.e2e; + +import java.util.Map; + +public class Input { + private String message; + private Map keys; + + public String getMessage() { + return message; + } + + public void setMessage(String message) { + this.message = message; + } + + public Map getKeys() { + return keys; + } + + public void setKeys(Map keys) { + this.keys = keys; + } +} diff --git a/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-core/reflect-config.json b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-core/reflect-config.json new file mode 100644 index 000000000..2780aca09 --- /dev/null +++ b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-core/reflect-config.json @@ -0,0 +1,13 @@ +[ + { + "name":"com.amazonaws.services.lambda.runtime.LambdaRuntime", + "methods":[{"name":"","parameterTypes":[] }], + "fields":[{"name":"logger"}], + "allPublicMethods":true + }, + { + "name":"com.amazonaws.services.lambda.runtime.LambdaRuntimeInternal", + "methods":[{"name":"","parameterTypes":[] }], + "allPublicMethods":true + } +] \ No newline at end of file diff --git a/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-events/reflect-config.json b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-events/reflect-config.json new file mode 100644 index 000000000..ddda5d5f1 --- /dev/null +++ b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-events/reflect-config.json @@ -0,0 +1,35 @@ +[ + { + "name": "com.amazonaws.services.lambda.runtime.events.APIGatewayProxyRequestEvent", + "allDeclaredFields": true, + "allDeclaredMethods": true, + "allDeclaredConstructors": true + }, + { + "name": "com.amazonaws.services.lambda.runtime.events.APIGatewayProxyRequestEvent$ProxyRequestContext", + "allDeclaredFields": true, + "allDeclaredMethods": true, + "allDeclaredConstructors": true + }, + { + "name": "com.amazonaws.services.lambda.runtime.events.APIGatewayProxyRequestEvent$RequestIdentity", + "allDeclaredFields": true, + "allDeclaredMethods": true, + "allDeclaredConstructors": true + }, + { + "name": "com.amazonaws.services.lambda.runtime.events.APIGatewayProxyResponseEvent", + "allDeclaredFields": true, + "allDeclaredMethods": true, + "allDeclaredConstructors": true + }, + { + "name": "com.amazonaws.services.lambda.runtime.events.APIGatewayProxyResponseEvent", + "allDeclaredConstructors": true, + "allPublicConstructors": true, + "allDeclaredMethods": true, + "allPublicMethods": true, + "allDeclaredClasses": true, + "allPublicClasses": true + } +] \ No newline at end of file diff --git a/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/jni-config.json b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/jni-config.json new file mode 100644 index 000000000..91be72f7a --- /dev/null +++ b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/jni-config.json @@ -0,0 +1,11 @@ +[ + { + "name":"com.amazonaws.services.lambda.runtime.api.client.runtimeapi.LambdaRuntimeClientException", + "methods":[{"name":"","parameterTypes":["java.lang.String","int"] }] + }, + { + "name":"com.amazonaws.services.lambda.runtime.api.client.runtimeapi.dto.InvocationRequest", + "fields":[{"name":"id"}, {"name":"invokedFunctionArn"}, {"name":"deadlineTimeInMs"}, {"name":"xrayTraceId"}, {"name":"clientContext"}, {"name":"cognitoIdentity"}, {"name": "tenantId"}, {"name":"content"}], + "allPublicMethods":true + } +] \ No newline at end of file diff --git a/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/native-image.properties b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/native-image.properties new file mode 100644 index 000000000..20f8b7801 --- /dev/null +++ b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/native-image.properties @@ -0,0 +1 @@ +Args = --initialize-at-build-time=jdk.xml.internal.SecuritySupport \ No newline at end of file diff --git a/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/reflect-config.json b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/reflect-config.json new file mode 100644 index 000000000..e69fa735c --- /dev/null +++ b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/reflect-config.json @@ -0,0 +1,61 @@ +[ + { + "name": "com.amazonaws.lambda.thirdparty.com.fasterxml.jackson.databind.deser.Deserializers[]" + }, + { + "name": "com.amazonaws.lambda.thirdparty.com.fasterxml.jackson.databind.ext.Java7SupportImpl", + "methods": [{ "name": "", "parameterTypes": [] }] + }, + { + "name": "com.amazonaws.services.lambda.runtime.LambdaRuntime", + "fields": [{ "name": "logger" }] + }, + { + "name": "com.amazonaws.services.lambda.runtime.logging.LogLevel", + "allDeclaredConstructors": true, + "allPublicConstructors": true, + "allDeclaredMethods": true, + "allPublicMethods": true, + "allDeclaredFields": true, + "allPublicFields": true + }, + { + "name": "com.amazonaws.services.lambda.runtime.logging.LogFormat", + "allDeclaredConstructors": true, + "allPublicConstructors": true, + "allDeclaredMethods": true, + "allPublicMethods": true, + "allDeclaredFields": true, + "allPublicFields": true + }, + { + "name": "java.lang.Void", + "methods": [{ "name": "", "parameterTypes": [] }] + }, + { + "name": "java.util.Collections$UnmodifiableMap", + "fields": [{ "name": "m" }] + }, + { + "name": "jdk.internal.module.IllegalAccessLogger", + "fields": [{ "name": "logger" }] + }, + { + "name": "sun.misc.Unsafe", + "fields": [{ "name": "theUnsafe" }] + }, + { + "name": "com.amazonaws.services.lambda.runtime.api.client.runtimeapi.dto.InvocationRequest", + "fields": [ + { "name": "id" }, + { "name": "invokedFunctionArn" }, + { "name": "deadlineTimeInMs" }, + { "name": "xrayTraceId" }, + { "name": "clientContext" }, + { "name": "cognitoIdentity" }, + { "name": "tenantId" }, + { "name": "content" } + ], + "allPublicMethods": true + } +] diff --git a/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/resource-config.json b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/resource-config.json new file mode 100644 index 000000000..1062b4249 --- /dev/null +++ b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/resource-config.json @@ -0,0 +1,19 @@ +{ + "resources": { + "includes": [ + { + "pattern": "\\Qjni/libaws-lambda-jni.linux-aarch_64.so\\E" + }, + { + "pattern": "\\Qjni/libaws-lambda-jni.linux-x86_64.so\\E" + }, + { + "pattern": "\\Qjni/libaws-lambda-jni.linux_musl-aarch_64.so\\E" + }, + { + "pattern": "\\Qjni/libaws-lambda-jni.linux_musl-x86_64.so\\E" + } + ] + }, + "bundles": [] +} \ No newline at end of file diff --git a/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-serialization/reflect-config.json b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-serialization/reflect-config.json new file mode 100644 index 000000000..9890688f9 --- /dev/null +++ b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-serialization/reflect-config.json @@ -0,0 +1,25 @@ +[ + { + "name": "com.amazonaws.lambda.thirdparty.com.fasterxml.jackson.databind.deser.Deserializers[]" + }, + { + "name": "com.amazonaws.lambda.thirdparty.com.fasterxml.jackson.databind.ext.Java7HandlersImpl", + "methods": [{ "name": "", "parameterTypes": [] }] + }, + { + "name": "com.amazonaws.lambda.thirdparty.com.fasterxml.jackson.databind.ext.Java7SupportImpl", + "methods": [{ "name": "", "parameterTypes": [] }] + }, + { + "name": "com.amazonaws.lambda.thirdparty.com.fasterxml.jackson.databind.ser.Serializers[]" + }, + { + "name": "org.joda.time.DateTime", + "allDeclaredConstructors": true, + "allPublicConstructors": true, + "allDeclaredMethods": true, + "allPublicMethods": true, + "allDeclaredClasses": true, + "allPublicClasses": true + } +] diff --git a/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/reflect-config.json b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/reflect-config.json new file mode 100644 index 000000000..9ddd235e2 --- /dev/null +++ b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/reflect-config.json @@ -0,0 +1,20 @@ +[ + { + "name": "software.amazon.lambda.powertools.e2e.Function", + "allDeclaredConstructors": true, + "allPublicConstructors": true, + "allDeclaredMethods": true, + "allPublicMethods": true, + "allDeclaredClasses": true, + "allPublicClasses": true + }, + { + "name": "software.amazon.lambda.powertools.e2e.Input", + "allDeclaredConstructors": true, + "allPublicConstructors": true, + "allDeclaredMethods": true, + "allPublicMethods": true, + "allDeclaredClasses": true, + "allPublicClasses": true + } +] diff --git a/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/resource-config.json b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/resource-config.json new file mode 100644 index 000000000..be6aac3f6 --- /dev/null +++ b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/resource-config.json @@ -0,0 +1,7 @@ +{ + "resources":{ + "includes":[{ + "pattern":"\\Qlog4j2.xml\\E" + }]}, + "bundles":[] +} diff --git a/powertools-e2e-tests/handlers/logging-functional/src/main/resources/log4j2.xml b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/log4j2.xml new file mode 100644 index 000000000..28e03a9e0 --- /dev/null +++ b/powertools-e2e-tests/handlers/logging-functional/src/main/resources/log4j2.xml @@ -0,0 +1,17 @@ + + + + + + + + + + + + + + + + + diff --git a/powertools-e2e-tests/handlers/pom.xml b/powertools-e2e-tests/handlers/pom.xml index efb6929cc..4c3b79000 100644 --- a/powertools-e2e-tests/handlers/pom.xml +++ b/powertools-e2e-tests/handlers/pom.xml @@ -30,6 +30,7 @@ largemessage_idempotent logging-log4j logging-logback + logging-functional tracing metrics idempotency @@ -62,6 +63,11 @@ powertools-logging-logback ${project.version} + + software.amazon.lambda + powertools-logging + ${project.version} + software.amazon.lambda powertools-tracing diff --git a/powertools-e2e-tests/src/test/java/software/amazon/lambda/powertools/LoggingE2ET.java b/powertools-e2e-tests/src/test/java/software/amazon/lambda/powertools/LoggingE2ET.java index f5d2cea84..20bc5394d 100644 --- a/powertools-e2e-tests/src/test/java/software/amazon/lambda/powertools/LoggingE2ET.java +++ b/powertools-e2e-tests/src/test/java/software/amazon/lambda/powertools/LoggingE2ET.java @@ -70,7 +70,7 @@ void tearDown() { } @ParameterizedTest - @ValueSource(strings = { "logging-log4j", "logging-logback" }) + @ValueSource(strings = { "logging-log4j", "logging-logback", "logging-functional" }) @Timeout(value = 15, unit = TimeUnit.MINUTES) void test_logInfoWithAdditionalKeys(String pathToFunction) throws JsonProcessingException { setupInfrastructure(pathToFunction); diff --git a/powertools-logging/pom.xml b/powertools-logging/pom.xml index 39fbc4386..89d097031 100644 --- a/powertools-logging/pom.xml +++ b/powertools-logging/pom.xml @@ -186,6 +186,7 @@ JSON + testService diff --git a/powertools-logging/powertools-logging-log4j/src/test/java/org/apache/logging/log4j/layout/template/json/resolver/PowerToolsResolverFactoryTest.java b/powertools-logging/powertools-logging-log4j/src/test/java/org/apache/logging/log4j/layout/template/json/resolver/PowerToolsResolverFactoryTest.java index 7eeffc78f..46b5b65d4 100644 --- a/powertools-logging/powertools-logging-log4j/src/test/java/org/apache/logging/log4j/layout/template/json/resolver/PowerToolsResolverFactoryTest.java +++ b/powertools-logging/powertools-logging-log4j/src/test/java/org/apache/logging/log4j/layout/template/json/resolver/PowerToolsResolverFactoryTest.java @@ -24,6 +24,7 @@ import java.nio.file.NoSuchFileException; import java.nio.file.Paths; import java.nio.file.StandardOpenOption; +import java.util.concurrent.atomic.AtomicBoolean; import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; @@ -35,6 +36,7 @@ import software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor; import software.amazon.lambda.powertools.common.stubs.TestLambdaContext; +import software.amazon.lambda.powertools.logging.PowertoolsLogging; import software.amazon.lambda.powertools.logging.internal.handler.PowertoolsLogEnabled; @Order(1) @@ -45,7 +47,10 @@ class PowerToolsResolverFactoryTest { @BeforeEach void setUp() throws IllegalAccessException, IOException { MDC.clear(); + // Reset cold start state writeStaticField(LambdaHandlerProcessor.class, "isColdStart", null, true); + writeStaticField(PowertoolsLogging.class, "hasBeenInitialized", new AtomicBoolean(false), true); + context = new TestLambdaContext(); // Make sure file is cleaned up before running tests try { diff --git a/powertools-logging/powertools-logging-logback/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaEcsEncoderTest.java b/powertools-logging/powertools-logging-logback/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaEcsEncoderTest.java index 898abec2e..74a11813b 100644 --- a/powertools-logging/powertools-logging-logback/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaEcsEncoderTest.java +++ b/powertools-logging/powertools-logging-logback/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaEcsEncoderTest.java @@ -18,11 +18,6 @@ import static org.assertj.core.api.Assertions.assertThat; import static org.assertj.core.api.Assertions.contentOf; -import ch.qos.logback.classic.Level; -import ch.qos.logback.classic.Logger; -import ch.qos.logback.classic.pattern.RootCauseFirstThrowableProxyConverter; -import ch.qos.logback.classic.spi.LoggingEvent; -import com.amazonaws.services.lambda.runtime.Context; import java.io.File; import java.io.IOException; import java.nio.channels.FileChannel; @@ -30,16 +25,26 @@ import java.nio.file.NoSuchFileException; import java.nio.file.Paths; import java.nio.file.StandardOpenOption; +import java.util.concurrent.atomic.AtomicBoolean; + import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Order; import org.junit.jupiter.api.Test; -import software.amazon.lambda.powertools.common.stubs.TestLambdaContext; import org.slf4j.LoggerFactory; import org.slf4j.MDC; + +import com.amazonaws.services.lambda.runtime.Context; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.pattern.RootCauseFirstThrowableProxyConverter; +import ch.qos.logback.classic.spi.LoggingEvent; import software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor; -import software.amazon.lambda.powertools.logging.logback.LambdaEcsEncoder; +import software.amazon.lambda.powertools.common.stubs.TestLambdaContext; +import software.amazon.lambda.powertools.logging.PowertoolsLogging; import software.amazon.lambda.powertools.logging.internal.handler.PowertoolsLogEnabled; +import software.amazon.lambda.powertools.logging.logback.LambdaEcsEncoder; @Order(3) class LambdaEcsEncoderTest { @@ -51,7 +56,10 @@ class LambdaEcsEncoderTest { @BeforeEach void setUp() throws IllegalAccessException, IOException { MDC.clear(); + // Reset cold start state writeStaticField(LambdaHandlerProcessor.class, "isColdStart", null, true); + writeStaticField(PowertoolsLogging.class, "hasBeenInitialized", new AtomicBoolean(false), true); + context = new TestLambdaContext(); // Make sure file is cleaned up before running tests try { diff --git a/powertools-logging/powertools-logging-logback/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaJsonEncoderTest.java b/powertools-logging/powertools-logging-logback/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaJsonEncoderTest.java index 326fa4b19..97770d3d0 100644 --- a/powertools-logging/powertools-logging-logback/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaJsonEncoderTest.java +++ b/powertools-logging/powertools-logging-logback/src/test/java/software/amazon/lambda/powertools/logging/internal/LambdaJsonEncoderTest.java @@ -43,6 +43,8 @@ import java.util.Collections; import java.util.Date; import java.util.TimeZone; +import java.util.concurrent.atomic.AtomicBoolean; + import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.Assertions; import org.junit.jupiter.api.BeforeEach; @@ -52,6 +54,7 @@ import org.slf4j.LoggerFactory; import org.slf4j.MDC; import software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor; +import software.amazon.lambda.powertools.logging.PowertoolsLogging; import software.amazon.lambda.powertools.logging.argument.StructuredArgument; import software.amazon.lambda.powertools.logging.argument.StructuredArguments; import software.amazon.lambda.powertools.logging.internal.handler.PowertoolsArguments; @@ -73,7 +76,10 @@ class LambdaJsonEncoderTest { @BeforeEach void setUp() throws IllegalAccessException, IOException { MDC.clear(); + // Reset cold start state writeStaticField(LambdaHandlerProcessor.class, "isColdStart", null, true); + writeStaticField(PowertoolsLogging.class, "hasBeenInitialized", new AtomicBoolean(false), true); + context = new TestLambdaContext(); // Make sure file is cleaned up before running tests try { diff --git a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/PowertoolsLogging.java b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/PowertoolsLogging.java index 1276c2a87..a79583f5b 100644 --- a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/PowertoolsLogging.java +++ b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/PowertoolsLogging.java @@ -14,21 +14,103 @@ package software.amazon.lambda.powertools.logging; +import static software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor.coldStartDone; +import static software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor.getXrayTraceId; +import static software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor.isColdStart; +import static software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor.serviceName; +import static software.amazon.lambda.powertools.logging.internal.LoggingConstants.LAMBDA_LOG_LEVEL; +import static software.amazon.lambda.powertools.logging.internal.LoggingConstants.POWERTOOLS_LOG_LEVEL; +import static software.amazon.lambda.powertools.logging.internal.LoggingConstants.POWERTOOLS_SAMPLING_RATE; +import static software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields.FUNCTION_COLD_START; +import static software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields.FUNCTION_TRACE_ID; +import static software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields.SAMPLING_RATE; +import static software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields.SERVICE; + +import java.util.Arrays; +import java.util.Locale; +import java.util.Random; +import java.util.concurrent.atomic.AtomicBoolean; + +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.MDC; +import org.slf4j.event.Level; + +import com.amazonaws.services.lambda.runtime.Context; +import com.fasterxml.jackson.databind.JsonNode; + +import io.burt.jmespath.Expression; import software.amazon.lambda.powertools.logging.internal.BufferManager; import software.amazon.lambda.powertools.logging.internal.LoggingManager; import software.amazon.lambda.powertools.logging.internal.LoggingManagerRegistry; +import software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields; +import software.amazon.lambda.powertools.utilities.JsonConfig; /** - * PowertoolsLogging provides a backend-independent API for log buffering operations. - * This class abstracts away the underlying logging framework (Log4j2, Logback) and - * provides a unified interface for buffer management. + * PowertoolsLogging provides a logging backend-agnostic API for managing Powertools logging functionality. + * This class abstracts away the underlying logging framework (Log4j2, Logback) and provides a unified + * interface for Lambda context extraction, correlation ID handling, sampling rate configuration, + * log buffering operations, and other Lambda-specific logging features. + * + *

This class serves as a programmatic alternative to AspectJ-based {@code @Logging} annotation, + * allowing developers to integrate Powertools logging capabilities without AspectJ dependencies.

+ * + * Key features: + *
    + *
  • Lambda context initialization with function metadata, trace ID, and service name
  • + *
  • Sampling rate configuration for DEBUG logging
  • + *
  • Backend-independent log buffer management (flush/clear operations)
  • + *
  • MDC state management for structured logging
  • + *
*/ public final class PowertoolsLogging { + private static final Logger LOG = LoggerFactory.getLogger(PowertoolsLogging.class); + private static final ThreadLocal SAMPLER = ThreadLocal.withInitial(Random::new); + private static AtomicBoolean hasBeenInitialized = new AtomicBoolean(false); + + static { + initializeLogLevel(); + } private PowertoolsLogging() { // Utility class } + private static void initializeLogLevel() { + if (POWERTOOLS_LOG_LEVEL != null) { + Level powertoolsLevel = getLevelFromString(POWERTOOLS_LOG_LEVEL); + if (LAMBDA_LOG_LEVEL != null) { + Level lambdaLevel = getLevelFromString(LAMBDA_LOG_LEVEL); + if (powertoolsLevel.toInt() < lambdaLevel.toInt()) { + LOG.warn( + "Current log level ({}) does not match AWS Lambda Advanced Logging Controls minimum log level ({}). This can lead to data loss, consider adjusting them.", + POWERTOOLS_LOG_LEVEL, LAMBDA_LOG_LEVEL); + } + } + setLogLevel(powertoolsLevel); + } else if (LAMBDA_LOG_LEVEL != null) { + setLogLevel(getLevelFromString(LAMBDA_LOG_LEVEL)); + } + } + + private static Level getLevelFromString(String level) { + if (Arrays.stream(Level.values()).anyMatch(slf4jLevel -> slf4jLevel.name().equalsIgnoreCase(level))) { + return Level.valueOf(level.toUpperCase(Locale.ROOT)); + } else { + // FATAL does not exist in slf4j + if ("FATAL".equalsIgnoreCase(level)) { + return Level.ERROR; + } + } + // default to INFO if incorrect value + return Level.INFO; + } + + private static void setLogLevel(Level logLevel) { + LoggingManager loggingManager = LoggingManagerRegistry.getLoggingManager(); + loggingManager.setLogLevel(logLevel); + } + /** * Flushes the log buffer for the current Lambda execution. * This method will flush any buffered logs to the output stream. @@ -52,4 +134,148 @@ public static void clearBuffer() { ((BufferManager) loggingManager).clearBuffer(); } } + + /** + * Initializes Lambda logging context with standard Powertools fields. + * This method should be called at the beginning of your Lambda handler to set up + * logging context with Lambda function information, trace ID, and service name. + * + * @param context the Lambda context provided by AWS Lambda runtime + */ + public static void initializeLogging(Context context) { + initializeLogging(context, 0.0, null, null); + } + + /** + * Initializes Lambda logging context with sampling rate configuration. + * This method sets up logging context and optionally enables DEBUG logging + * based on the provided sampling rate. + * + * @param context the Lambda context provided by AWS Lambda runtime + * @param samplingRate sampling rate for DEBUG logging (0.0 to 1.0) + */ + public static void initializeLogging(Context context, double samplingRate) { + initializeLogging(context, samplingRate, null, null); + } + + /** + * Initializes Lambda logging context with correlation ID extraction. + * This method sets up logging context and extracts correlation ID from the event + * using the provided JSON path. + * + * @param context the Lambda context provided by AWS Lambda runtime + * @param correlationIdPath JSON path to extract correlation ID from event + * @param event the Lambda event object + */ + public static void initializeLogging(Context context, String correlationIdPath, Object event) { + initializeLogging(context, 0.0, correlationIdPath, event); + } + + /** + * Initializes Lambda logging context with full configuration. + * This method sets up logging context with Lambda function information, + * configures sampling rate for DEBUG logging, and optionally extracts + * correlation ID from the event. + * + * This method is tread-safe. + * + * @param context the Lambda context provided by AWS Lambda runtime + * @param samplingRate sampling rate for DEBUG logging (0.0 to 1.0) + * @param correlationIdPath JSON path to extract correlation ID from event (can be null) + * @param event the Lambda event object (required if correlationIdPath is provided) + */ + public static void initializeLogging(Context context, double samplingRate, String correlationIdPath, Object event) { + + addLambdaContextToLoggingContext(context); + setLogLevelBasedOnSamplingRate(samplingRate); + getXrayTraceId().ifPresent(xRayTraceId -> MDC.put(FUNCTION_TRACE_ID.getName(), xRayTraceId)); + + if (correlationIdPath != null && !correlationIdPath.isEmpty() && event != null) { + captureCorrelationId(correlationIdPath, event); + } + } + + // Synchronized since isColdStart() is a globally managed constant in LambdaHandlerProcessor + private static synchronized void addLambdaContextToLoggingContext(Context context) { + if (context != null) { + PowertoolsLoggedFields.setValuesFromLambdaContext(context).forEach(MDC::put); + } + + MDC.put(FUNCTION_COLD_START.getName(), isColdStart() ? "true" : "false"); + if (hasBeenInitialized.compareAndSet(false, true)) { + coldStartDone(); + } + MDC.put(SERVICE.getName(), serviceName()); + } + + private static void setLogLevelBasedOnSamplingRate(double samplingRate) { + double effectiveSamplingRate = getEffectiveSamplingRate(samplingRate); + + if (effectiveSamplingRate < 0 || effectiveSamplingRate > 1) { + LOG.warn("Skipping sampling rate configuration because of invalid value. Sampling rate: {}", + effectiveSamplingRate); + return; + } + + MDC.put(SAMPLING_RATE.getName(), String.valueOf(effectiveSamplingRate)); + + if (effectiveSamplingRate == 0) { + return; + } + + float sample = SAMPLER.get().nextFloat(); + if (effectiveSamplingRate > sample) { + LoggingManager loggingManager = LoggingManagerRegistry.getLoggingManager(); + loggingManager.setLogLevel(Level.DEBUG); + LOG.debug( + "Changed log level to DEBUG based on Sampling configuration. Sampling Rate: {}, Sampler Value: {}.", + effectiveSamplingRate, sample); + } + } + + // The environment variable takes precedence over manually set sampling rate + private static double getEffectiveSamplingRate(double samplingRate) { + String envSampleRate = POWERTOOLS_SAMPLING_RATE; + if (envSampleRate != null) { + try { + return Double.parseDouble(envSampleRate); + } catch (NumberFormatException e) { + LOG.warn( + "Skipping sampling rate on environment variable configuration because of invalid value. Sampling rate: {}", + envSampleRate); + } + } + + return samplingRate; + } + + private static void captureCorrelationId(String correlationIdPath, Object event) { + try { + JsonNode jsonNode = JsonConfig.get().getObjectMapper().valueToTree(event); + Expression jmesExpression = JsonConfig.get().getJmesPath().compile(correlationIdPath); + JsonNode node = jmesExpression.search(jsonNode); + + String asText = node.asText(); + if (asText != null && !asText.isEmpty()) { + MDC.put(PowertoolsLoggedFields.CORRELATION_ID.getName(), asText); + } else { + LOG.warn("Unable to extract any correlation id. Is your function expecting supported event type?"); + } + } catch (Exception e) { + LOG.warn("Failed to capture correlation id from event.", e); + } + } + + /** + * Clears MDC state and log buffer. + * + * @param clearMdcState whether to clear MDC state + */ + public static void clearState(boolean clearMdcState) { + if (clearMdcState) { + MDC.clear(); + } + clearBuffer(); + SAMPLER.remove(); + } } 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 591283996..272c4bff9 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 @@ -15,25 +15,14 @@ package software.amazon.lambda.powertools.logging.internal; import static java.nio.charset.StandardCharsets.UTF_8; -import static software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor.coldStartDone; import static software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor.extractContext; -import static software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor.getXrayTraceId; -import static software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor.isColdStart; import static software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor.isHandlerMethod; import static software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor.placedOnRequestHandler; import static software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor.placedOnStreamHandler; -import static software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor.serviceName; import static software.amazon.lambda.powertools.logging.argument.StructuredArguments.entry; -import static software.amazon.lambda.powertools.logging.internal.LoggingConstants.LAMBDA_LOG_LEVEL; import static software.amazon.lambda.powertools.logging.internal.LoggingConstants.POWERTOOLS_LOG_ERROR; import static software.amazon.lambda.powertools.logging.internal.LoggingConstants.POWERTOOLS_LOG_EVENT; -import static software.amazon.lambda.powertools.logging.internal.LoggingConstants.POWERTOOLS_LOG_LEVEL; import static software.amazon.lambda.powertools.logging.internal.LoggingConstants.POWERTOOLS_LOG_RESPONSE; -import static software.amazon.lambda.powertools.logging.internal.LoggingConstants.POWERTOOLS_SAMPLING_RATE; -import static software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields.CORRELATION_ID; -import static software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields.FUNCTION_COLD_START; -import static software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields.FUNCTION_TRACE_ID; -import static software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields.SERVICE; import java.io.ByteArrayInputStream; import java.io.ByteArrayOutputStream; @@ -42,9 +31,6 @@ import java.io.InputStreamReader; import java.io.OutputStream; import java.io.OutputStreamWriter; -import java.util.Arrays; -import java.util.Locale; -import java.util.Random; import org.aspectj.lang.ProceedingJoinPoint; import org.aspectj.lang.annotation.Around; @@ -53,66 +39,22 @@ import org.aspectj.lang.annotation.Pointcut; import org.slf4j.Logger; import org.slf4j.LoggerFactory; -import org.slf4j.MDC; import org.slf4j.MarkerFactory; -import org.slf4j.event.Level; import com.amazonaws.services.lambda.runtime.Context; -import com.fasterxml.jackson.databind.JsonNode; -import io.burt.jmespath.Expression; import software.amazon.lambda.powertools.logging.Logging; +import software.amazon.lambda.powertools.logging.PowertoolsLogging; import software.amazon.lambda.powertools.utilities.JsonConfig; @Aspect @DeclarePrecedence("*, software.amazon.lambda.powertools.logging.internal.LambdaLoggingAspect") public final class LambdaLoggingAspect { private static final Logger LOG = LoggerFactory.getLogger(LambdaLoggingAspect.class); - private static final Random SAMPLER = new Random(); - private static Level LEVEL_AT_INITIALISATION; /* not final for test purpose */ - private static final LoggingManager LOGGING_MANAGER; static { LOGGING_MANAGER = LoggingManagerRegistry.getLoggingManager(); - - setLogLevel(); - - LEVEL_AT_INITIALISATION = LOGGING_MANAGER.getLogLevel(LOG); - } - - static void setLogLevel() { - if (POWERTOOLS_LOG_LEVEL != null) { - Level powertoolsLevel = getLevelFromString(POWERTOOLS_LOG_LEVEL); - if (LAMBDA_LOG_LEVEL != null) { - Level lambdaLevel = getLevelFromString(LAMBDA_LOG_LEVEL); - if (powertoolsLevel.toInt() < lambdaLevel.toInt()) { - LOG.warn( - "Current log level ({}) does not match AWS Lambda Advanced Logging Controls minimum log level ({}). This can lead to data loss, consider adjusting them.", - POWERTOOLS_LOG_LEVEL, LAMBDA_LOG_LEVEL); - } - } - setLogLevels(powertoolsLevel); - } else if (LAMBDA_LOG_LEVEL != null) { - setLogLevels(getLevelFromString(LAMBDA_LOG_LEVEL)); - } - } - - private static Level getLevelFromString(String level) { - if (Arrays.stream(Level.values()).anyMatch(slf4jLevel -> slf4jLevel.name().equalsIgnoreCase(level))) { - return Level.valueOf(level.toUpperCase(Locale.ROOT)); - } else { - // FATAL does not exist in slf4j - if ("FATAL".equalsIgnoreCase(level)) { - return Level.ERROR; - } - } - // default to INFO if incorrect value - return Level.INFO; - } - - private static void setLogLevels(Level logLevel) { - LOGGING_MANAGER.setLogLevel(logLevel); } @SuppressWarnings({ "EmptyMethod" }) @@ -131,17 +73,19 @@ public Object around(ProceedingJoinPoint pjp, boolean isOnRequestHandler = placedOnRequestHandler(pjp); boolean isOnRequestStreamHandler = placedOnStreamHandler(pjp); - setLogLevelBasedOnSamplingRate(pjp, logging); - addLambdaContextToLoggingContext(pjp); - getXrayTraceId().ifPresent(xRayTraceId -> MDC.put(FUNCTION_TRACE_ID.getName(), xRayTraceId)); - - Object[] proceedArgs = logEvent(pjp, logging, isOnRequestHandler, isOnRequestStreamHandler); + // Initialize logging using PowertoolsLogging + Context context = extractContext(pjp); + Object[] proceedArgs = pjp.getArgs(); - if (!logging.correlationIdPath().isEmpty()) { - captureCorrelationId(logging.correlationIdPath(), proceedArgs, isOnRequestHandler, - isOnRequestStreamHandler); + if (isHandlerMethod(pjp) && context != null) { + Object event = extractEventForCorrelationId(logging, isOnRequestHandler, isOnRequestStreamHandler, + proceedArgs); + PowertoolsLogging.initializeLogging(context, logging.samplingRate(), + logging.correlationIdPath().isEmpty() ? null : logging.correlationIdPath(), event); } + logEvent(pjp, logging, isOnRequestHandler, isOnRequestStreamHandler, proceedArgs); + @SuppressWarnings("PMD.CloseResource") // Lambda-owned stream, not ours to close OutputStream backupOutputStream = null; if (isOnRequestStreamHandler) { @@ -160,7 +104,7 @@ public Object around(ProceedingJoinPoint pjp, handleException(pjp, logging, t); throw t; } finally { - performCleanup(logging); + PowertoolsLogging.clearState(logging.clearState()); } logResponse(pjp, logging, lambdaFunctionResponse, isOnRequestHandler, isOnRequestStreamHandler, @@ -169,74 +113,18 @@ public Object around(ProceedingJoinPoint pjp, return lambdaFunctionResponse; } - private Object[] logEvent(ProceedingJoinPoint pjp, Logging logging, - boolean isOnRequestHandler, boolean isOnRequestStreamHandler) { - Object[] proceedArgs = pjp.getArgs(); + private void logEvent(ProceedingJoinPoint pjp, Logging logging, + boolean isOnRequestHandler, boolean isOnRequestStreamHandler, Object[] proceedArgs) { if (logging.logEvent() || POWERTOOLS_LOG_EVENT) { if (isOnRequestHandler) { - logRequestHandlerEvent(pjp, pjp.getArgs()[0]); + logRequestHandlerEvent(pjp, proceedArgs[0]); } else if (isOnRequestStreamHandler) { - proceedArgs = logRequestStreamHandlerEvent(pjp); - } - } - return proceedArgs; - } - - private void addLambdaContextToLoggingContext(ProceedingJoinPoint pjp) { - Context extractedContext = extractContext(pjp); - - if (extractedContext != null) { - PowertoolsLoggedFields.setValuesFromLambdaContext(extractedContext).forEach(MDC::put); - MDC.put(FUNCTION_COLD_START.getName(), isColdStart() ? "true" : "false"); - MDC.put(SERVICE.getName(), serviceName()); - } - } - - private void setLogLevelBasedOnSamplingRate(final ProceedingJoinPoint pjp, - final Logging logging) { - double samplingRate = samplingRate(logging); - - if (isHandlerMethod(pjp)) { - - if (samplingRate < 0 || samplingRate > 1) { - LOG.warn("Skipping sampling rate configuration because of invalid value. Sampling rate: {}", - samplingRate); - return; - } - - MDC.put(PowertoolsLoggedFields.SAMPLING_RATE.getName(), String.valueOf(samplingRate)); - - if (samplingRate == 0) { - return; - } - - float sample = SAMPLER.nextFloat(); - - if (samplingRate > sample) { - setLogLevels(Level.DEBUG); - - LOG.debug("Changed log level to DEBUG based on Sampling configuration. " - + "Sampling Rate: {}, Sampler Value: {}.", samplingRate, sample); - } else if (LEVEL_AT_INITIALISATION != LOGGING_MANAGER.getLogLevel(LOG)) { - setLogLevels(LEVEL_AT_INITIALISATION); + logRequestStreamHandlerEvent(pjp, proceedArgs); } } } - private double samplingRate(final Logging logging) { - String sampleRate = POWERTOOLS_SAMPLING_RATE; - if (null != sampleRate) { - try { - return Double.parseDouble(sampleRate); - } catch (NumberFormatException e) { - LOG.warn("Skipping sampling rate on environment variable configuration because of invalid " - + "value. Sampling rate: {}", sampleRate); - } - } - return logging.samplingRate(); - } - @SuppressWarnings("java:S3457") private void logRequestHandlerEvent(final ProceedingJoinPoint pjp, final Object event) { Logger log = logger(pjp); @@ -246,12 +134,11 @@ private void logRequestHandlerEvent(final ProceedingJoinPoint pjp, final Object } @SuppressWarnings("java:S3457") - private Object[] logRequestStreamHandlerEvent(final ProceedingJoinPoint pjp) { - Object[] args = pjp.getArgs(); + private void logRequestStreamHandlerEvent(final ProceedingJoinPoint pjp, Object[] args) { Logger log = logger(pjp); if (log.isInfoEnabled()) { try { - byte[] bytes = bytesFromInputStreamSafely((InputStream) pjp.getArgs()[0]); + byte[] bytes = bytesFromInputStreamSafely((InputStream) args[0]); args[0] = new ByteArrayInputStream(bytes); // do not log asJson as it can be something else (String, XML...) log.info("Handler Event", entry("event", new String(bytes, UTF_8))); @@ -259,7 +146,6 @@ private Object[] logRequestStreamHandlerEvent(final ProceedingJoinPoint pjp) { LOG.warn("Failed to log event from supplied input stream.", e); } } - return args; } @SuppressWarnings("java:S3457") @@ -279,38 +165,6 @@ private void logRequestStreamHandlerResponse(final ProceedingJoinPoint pjp, fina } } - private void captureCorrelationId(final String correlationIdPath, - Object[] proceedArgs, - final boolean isOnRequestHandler, - final boolean isOnRequestStreamHandler) { - if (isOnRequestHandler) { - JsonNode jsonNode = JsonConfig.get().getObjectMapper().valueToTree(proceedArgs[0]); - setCorrelationIdFromNode(correlationIdPath, jsonNode); - } else if (isOnRequestStreamHandler) { - try { - byte[] bytes = bytesFromInputStreamSafely((InputStream) proceedArgs[0]); - JsonNode jsonNode = JsonConfig.get().getObjectMapper().readTree(bytes); - proceedArgs[0] = new ByteArrayInputStream(bytes); - - setCorrelationIdFromNode(correlationIdPath, jsonNode); - } catch (IOException e) { - LOG.warn("Failed to capture correlation id on event from supplied input stream.", e); - } - } - } - - private void setCorrelationIdFromNode(String correlationIdPath, JsonNode jsonNode) { - Expression jmesExpression = JsonConfig.get().getJmesPath().compile(correlationIdPath); - JsonNode node = jmesExpression.search(jsonNode); - - String asText = node.asText(); - if (null != asText && !asText.isEmpty()) { - MDC.put(CORRELATION_ID.getName(), asText); - } else { - LOG.warn("Unable to extract any correlation id. Is your function expecting supported event type?"); - } - } - private byte[] bytesFromInputStreamSafely(final InputStream inputStream) throws IOException { try (ByteArrayOutputStream out = new ByteArrayOutputStream(); InputStreamReader reader = new InputStreamReader(inputStream, UTF_8); @@ -348,16 +202,6 @@ private void handleException(ProceedingJoinPoint pjp, Logging logging, Throwable } } - private void performCleanup(Logging logging) { - if (logging.clearState()) { - MDC.clear(); - } - if (LOGGING_MANAGER instanceof BufferManager) { - ((BufferManager) LOGGING_MANAGER).clearBuffer(); - } - coldStartDone(); - } - private void logResponse(ProceedingJoinPoint pjp, Logging logging, Object lambdaFunctionResponse, boolean isOnRequestHandler, boolean isOnRequestStreamHandler, OutputStream backupOutputStream, Object[] proceedArgs) throws IOException { @@ -372,6 +216,28 @@ private void logResponse(ProceedingJoinPoint pjp, Logging logging, Object lambda } } + private Object extractEventForCorrelationId(Logging logging, boolean isOnRequestHandler, + boolean isOnRequestStreamHandler, Object[] proceedArgs) { + if (logging.correlationIdPath().isEmpty()) { + return null; + } + + if (isOnRequestHandler && proceedArgs.length > 0) { + return proceedArgs[0]; + } else if (isOnRequestStreamHandler && proceedArgs.length > 0) { + try { + byte[] bytes = bytesFromInputStreamSafely((InputStream) proceedArgs[0]); + // Parse JSON string to Object for correlation ID extraction + Object event = JsonConfig.get().getObjectMapper().readTree(bytes); + proceedArgs[0] = new ByteArrayInputStream(bytes); // Restore stream + return event; + } catch (IOException e) { + LOG.warn("Failed to read event from input stream for correlation ID extraction.", e); + } + } + return null; + } + private Logger logger(final ProceedingJoinPoint pjp) { return LoggerFactory.getLogger(pjp.getSignature().getDeclaringType()); } diff --git a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LoggingConstants.java b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LoggingConstants.java index 989608a77..511b12ace 100644 --- a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LoggingConstants.java +++ b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LoggingConstants.java @@ -14,12 +14,15 @@ package software.amazon.lambda.powertools.logging.internal; -class LoggingConstants { - static String LAMBDA_LOG_LEVEL = System.getenv("AWS_LAMBDA_LOG_LEVEL"); /* not final for test purpose */ +public final class LoggingConstants { + @SuppressWarnings({"java:S1104", "java:S1444", "java:S3008"}) + public static String LAMBDA_LOG_LEVEL = System.getenv("AWS_LAMBDA_LOG_LEVEL"); /* not final for test purpose */ - static String POWERTOOLS_LOG_LEVEL = System.getenv("POWERTOOLS_LOG_LEVEL"); /* not final for test purpose */ + @SuppressWarnings({"java:S1104", "java:S1444", "java:S3008"}) + public static String POWERTOOLS_LOG_LEVEL = System.getenv("POWERTOOLS_LOG_LEVEL"); /* not final for test purpose */ - static String POWERTOOLS_SAMPLING_RATE = System.getenv("POWERTOOLS_LOGGER_SAMPLE_RATE"); /* not final for test purpose */ + @SuppressWarnings({"java:S1104", "java:S1444", "java:S3008"}) + public static String POWERTOOLS_SAMPLING_RATE = System.getenv("POWERTOOLS_LOGGER_SAMPLE_RATE"); /* not final for test purpose */ static boolean POWERTOOLS_LOG_EVENT = "true".equals(System.getenv("POWERTOOLS_LOGGER_LOG_EVENT")); /* not final for test purpose */ diff --git a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/PowertoolsLoggedFields.java b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/PowertoolsLoggedFields.java index 6e0047f4f..2545396d2 100644 --- a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/PowertoolsLoggedFields.java +++ b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/PowertoolsLoggedFields.java @@ -47,7 +47,7 @@ public static List stringValues() { return Stream.of(values()).map(PowertoolsLoggedFields::getName).collect(Collectors.toList()); } - static Map setValuesFromLambdaContext(Context context) { + public static Map setValuesFromLambdaContext(Context context) { Map hashMap = new HashMap<>(); hashMap.put(FUNCTION_NAME.name, context.getFunctionName()); diff --git a/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/PowertoolsLoggingTest.java b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/PowertoolsLoggingTest.java index ea3a2f3f6..0691270f8 100644 --- a/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/PowertoolsLoggingTest.java +++ b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/PowertoolsLoggingTest.java @@ -14,23 +14,78 @@ package software.amazon.lambda.powertools.logging; +import static org.apache.commons.lang3.reflect.FieldUtils.writeStaticField; import static org.assertj.core.api.Assertions.assertThat; +import static org.assertj.core.api.Assertions.assertThatNoException; +import static org.assertj.core.api.Assertions.contentOf; +import java.io.File; +import java.io.IOException; +import java.lang.reflect.Method; +import java.nio.channels.FileChannel; +import java.nio.file.NoSuchFileException; +import java.nio.file.Paths; +import java.nio.file.StandardOpenOption; +import java.util.Map; +import java.util.concurrent.atomic.AtomicBoolean; + +import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.MDC; + +import com.amazonaws.services.lambda.runtime.Context; +import software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor; +import software.amazon.lambda.powertools.common.stubs.TestLambdaContext; +import software.amazon.lambda.powertools.logging.internal.LoggingConstants; import software.amazon.lambda.powertools.logging.internal.LoggingManagerRegistry; +import software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields; import software.amazon.lambda.powertools.logging.internal.TestLoggingManager; class PowertoolsLoggingTest { + private static final Logger LOG = LoggerFactory.getLogger(PowertoolsLoggingTest.class); private TestLoggingManager testManager; + private Context context; @BeforeEach - void setUp() { + void setUp() throws IllegalAccessException, IOException { // Get the TestLoggingManager instance from registry testManager = (TestLoggingManager) LoggingManagerRegistry.getLoggingManager(); testManager.resetBufferState(); + + context = new TestLambdaContext(); + + // Reset environment variables for clean test isolation + writeStaticField(LoggingConstants.class, "LAMBDA_LOG_LEVEL", null, true); + writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", null, true); + writeStaticField(LoggingConstants.class, "POWERTOOLS_SAMPLING_RATE", null, true); + + // Clear MDC for clean test isolation + MDC.clear(); + + // Reset cold start state + writeStaticField(LambdaHandlerProcessor.class, "isColdStart", null, true); + writeStaticField(PowertoolsLogging.class, "hasBeenInitialized", new AtomicBoolean(false), true); + + try { + FileChannel.open(Paths.get("target/logfile.json"), StandardOpenOption.WRITE).truncate(0).close(); + } catch (NoSuchFileException e) { + // may not be there in the first run + } + } + + @AfterEach + void cleanUp() throws IOException { + // Make sure file is cleaned up + try { + FileChannel.open(Paths.get("target/logfile.json"), StandardOpenOption.WRITE).truncate(0).close(); + } catch (NoSuchFileException e) { + // may not be there in the first run + } } @Test @@ -50,4 +105,333 @@ void testClearBuffer_shouldCallBufferManager() { // THEN assertThat(testManager.isBufferCleared()).isTrue(); } + + @Test + void shouldLogDebugWhenPowertoolsLevelEnvVarIsDebug() throws IllegalAccessException { + // GIVEN + writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", "DEBUG", true); + + // WHEN + reinitializeLogLevel(); + + // THEN + assertThat(LOG.isDebugEnabled()).isTrue(); + } + + @Test + void shouldLogInfoWhenPowertoolsLevelEnvVarIsInfo() throws IllegalAccessException { + // GIVEN + writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", "INFO", true); + + // WHEN + reinitializeLogLevel(); + + // THEN + assertThat(LOG.isDebugEnabled()).isFalse(); + assertThat(LOG.isInfoEnabled()).isTrue(); + } + + @Test + void shouldLogInfoWhenPowertoolsLevelEnvVarIsInvalid() throws IllegalAccessException { + // GIVEN + writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", "INVALID", true); + + // WHEN + reinitializeLogLevel(); + + // THEN + assertThat(LOG.isDebugEnabled()).isFalse(); + assertThat(LOG.isInfoEnabled()).isTrue(); + } + + @Test + void shouldLogWarnWhenPowertoolsLevelEnvVarIsWarn() throws IllegalAccessException { + // GIVEN + writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", "WARN", true); + + // WHEN + reinitializeLogLevel(); + + // THEN + assertThat(LOG.isDebugEnabled()).isFalse(); + assertThat(LOG.isInfoEnabled()).isFalse(); + assertThat(LOG.isWarnEnabled()).isTrue(); + } + + @Test + void shouldLogErrorWhenPowertoolsLevelEnvVarIsError() throws IllegalAccessException { + // GIVEN + writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", "ERROR", true); + + // WHEN + reinitializeLogLevel(); + + // THEN + assertThat(LOG.isDebugEnabled()).isFalse(); + assertThat(LOG.isInfoEnabled()).isFalse(); + assertThat(LOG.isWarnEnabled()).isFalse(); + assertThat(LOG.isErrorEnabled()).isTrue(); + } + + @Test + void shouldLogErrorWhenPowertoolsLevelEnvVarIsFatal() throws IllegalAccessException { + // GIVEN + writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", "FATAL", true); + + // WHEN + reinitializeLogLevel(); + + // THEN + assertThat(LOG.isDebugEnabled()).isFalse(); + assertThat(LOG.isInfoEnabled()).isFalse(); + assertThat(LOG.isWarnEnabled()).isFalse(); + assertThat(LOG.isErrorEnabled()).isTrue(); + } + + @Test + void shouldLogWarnWhenPowertoolsLevelEnvVarIsWarnAndLambdaLevelVarIsInfo() throws IllegalAccessException { + // GIVEN + writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", "WARN", true); + writeStaticField(LoggingConstants.class, "LAMBDA_LOG_LEVEL", "INFO", true); + + // WHEN + reinitializeLogLevel(); + + // THEN + assertThat(LOG.isDebugEnabled()).isFalse(); + assertThat(LOG.isInfoEnabled()).isFalse(); + assertThat(LOG.isWarnEnabled()).isTrue(); + File logFile = new File("target/logfile.json"); + assertThat(contentOf(logFile)) + .doesNotContain(" does not match AWS Lambda Advanced Logging Controls minimum log level"); + } + + @Test + void shouldLogInfoWhenPowertoolsLevelEnvVarIsInfoAndLambdaLevelVarIsWarn() throws IllegalAccessException { + // GIVEN + writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", "INFO", true); + writeStaticField(LoggingConstants.class, "LAMBDA_LOG_LEVEL", "WARN", true); + + // WHEN + reinitializeLogLevel(); + + // THEN + assertThat(LOG.isDebugEnabled()).isFalse(); + assertThat(LOG.isInfoEnabled()).isTrue(); + File logFile = new File("target/logfile.json"); + // should log a warning as powertools level is lower than lambda level + assertThat(contentOf(logFile)).contains( + "Current log level (INFO) does not match AWS Lambda Advanced Logging Controls minimum log level (WARN). This can lead to data loss, consider adjusting them."); + } + + @Test + void shouldLogWarnWhenPowertoolsLevelEnvVarINotSetAndLambdaLevelVarIsWarn() throws IllegalAccessException { + // GIVEN + writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", null, true); + writeStaticField(LoggingConstants.class, "LAMBDA_LOG_LEVEL", "WARN", true); + + // WHEN + reinitializeLogLevel(); + + // THEN + assertThat(LOG.isDebugEnabled()).isFalse(); + assertThat(LOG.isInfoEnabled()).isFalse(); + assertThat(LOG.isWarnEnabled()).isTrue(); + } + + @Test + void initializeLogging_withContextOnly_shouldSetLambdaFields() { + // WHEN + PowertoolsLogging.initializeLogging(context); + + // THEN + Map mdcMap = MDC.getCopyOfContextMap(); + assertThat(mdcMap) + .containsEntry(PowertoolsLoggedFields.FUNCTION_NAME.getName(), "test-function") + .containsEntry(PowertoolsLoggedFields.FUNCTION_VERSION.getName(), "1") + .containsEntry(PowertoolsLoggedFields.FUNCTION_COLD_START.getName(), "true") + .containsEntry(PowertoolsLoggedFields.SERVICE.getName(), "testService"); + } + + @Test + void initializeLogging_withSamplingRate_shouldSetSamplingRateInMdc() { + // WHEN + PowertoolsLogging.initializeLogging(context, 0.5); + + // THEN + assertThat(MDC.get(PowertoolsLoggedFields.SAMPLING_RATE.getName())).isEqualTo("0.5"); + } + + @Test + void initializeLogging_withCorrelationId_shouldExtractFromEvent() { + // GIVEN + Map event = Map.of("requestContext", Map.of("requestId", "test-correlation-id")); + + // WHEN + PowertoolsLogging.initializeLogging(context, "requestContext.requestId", event); + + // THEN + assertThat(MDC.get(PowertoolsLoggedFields.CORRELATION_ID.getName())).isEqualTo("test-correlation-id"); + } + + @Test + void initializeLogging_withFullConfiguration_shouldSetAllFields() { + // GIVEN + Map event = Map.of("id", "correlation-123"); + + // WHEN + PowertoolsLogging.initializeLogging(context, 0.5, "id", event); + + // THEN + Map mdcMap = MDC.getCopyOfContextMap(); + assertThat(mdcMap) + .containsEntry(PowertoolsLoggedFields.FUNCTION_NAME.getName(), "test-function") + .containsEntry(PowertoolsLoggedFields.CORRELATION_ID.getName(), "correlation-123") + .containsEntry(PowertoolsLoggedFields.SAMPLING_RATE.getName(), "0.5"); + } + + @Test + void initializeLogging_withInvalidSamplingRate_shouldSkipSampling() { + // WHEN + PowertoolsLogging.initializeLogging(context, 2.0); + + // THEN + assertThat(MDC.get(PowertoolsLoggedFields.SAMPLING_RATE.getName())).isNull(); + } + + @Test + void initializeLogging_withEnvVarAndParameter_shouldUseEnvVarPrecedence() throws IllegalAccessException { + // GIVEN + writeStaticField(LoggingConstants.class, "POWERTOOLS_SAMPLING_RATE", "0.8", true); + + // WHEN + PowertoolsLogging.initializeLogging(context, 0.3); + + // THEN + assertThat(MDC.get(PowertoolsLoggedFields.SAMPLING_RATE.getName())).isEqualTo("0.8"); + } + + @Test + void initializeLogging_calledTwice_shouldMarkColdStartDoneOnSecondCall() throws IllegalAccessException { + // GIVEN + writeStaticField(PowertoolsLogging.class, "hasBeenInitialized", new AtomicBoolean(false), true); + + // WHEN - First call + PowertoolsLogging.initializeLogging(context); + String firstCallColdStart = MDC.get(PowertoolsLoggedFields.FUNCTION_COLD_START.getName()); + + // WHEN - Second call + PowertoolsLogging.initializeLogging(context); + String secondCallColdStart = MDC.get(PowertoolsLoggedFields.FUNCTION_COLD_START.getName()); + + // THEN + assertThat(firstCallColdStart).isEqualTo("true"); + assertThat(secondCallColdStart).isEqualTo("false"); + } + + @Test + void initializeLogging_withNullContext_shouldNotThrow() { + // WHEN & THEN + assertThatNoException().isThrownBy(() -> { + PowertoolsLogging.initializeLogging(null); + PowertoolsLogging.initializeLogging(null, 0.5); + PowertoolsLogging.initializeLogging(null, "path", Map.of()); + PowertoolsLogging.initializeLogging(null, 0.5, "path", Map.of()); + }); + } + + @Test + void clearState_shouldClearMdcAndBuffer() { + // GIVEN + MDC.put("test", "value"); + + // WHEN + PowertoolsLogging.clearState(true); + + // THEN + assertThat(MDC.getCopyOfContextMap()).isNull(); + assertThat(testManager.isBufferCleared()).isTrue(); + } + + @Test + void clearState_withoutMdcClear_shouldOnlyClearBuffer() { + // GIVEN + MDC.put("test", "value"); + + // WHEN + PowertoolsLogging.clearState(false); + + // THEN + assertThat(MDC.get("test")).isEqualTo("value"); + assertThat(testManager.isBufferCleared()).isTrue(); + } + + @Test + void initializeLogging_concurrentCalls_shouldBeThreadSafe() throws InterruptedException { + // GIVEN + int threadCount = 10; + Thread[] threads = new Thread[threadCount]; + String[] samplingRates = new String[threadCount]; + boolean[] coldStarts = new boolean[threadCount]; + boolean[] success = new boolean[threadCount]; + + // WHEN - Multiple threads call initializeLogging with alternating sampling rates + for (int i = 0; i < threadCount; i++) { + final int threadIndex = i; + final double samplingRate = (i % 2 == 0) ? 1.0 : 0.0; // Alternate between 1.0 and 0.0 + + threads[i] = new Thread(() -> { + try { + PowertoolsLogging.initializeLogging(context, samplingRate); + + // Capture the sampling rate and cold start values set in MDC (thread-local) + samplingRates[threadIndex] = MDC.get(PowertoolsLoggedFields.SAMPLING_RATE.getName()); + coldStarts[threadIndex] = Boolean + .parseBoolean(MDC.get(PowertoolsLoggedFields.FUNCTION_COLD_START.getName())); + success[threadIndex] = true; + + // Clean up thread-local state + PowertoolsLogging.clearState(true); + } catch (Exception e) { + success[threadIndex] = false; + } + }); + } + + // Start all threads + for (Thread thread : threads) { + thread.start(); + } + + // Wait for all threads to complete + for (Thread thread : threads) { + thread.join(); + } + + // THEN - All threads should complete successfully + for (boolean result : success) { + assertThat(result).isTrue(); + } + + // THEN - Each thread should have its own sampling rate in MDC and exactly one invocation was a cold start + int coldStartCount = 0; + for (int i = 0; i < threadCount; i++) { + String expectedSamplingRate = (i % 2 == 0) ? "1.0" : "0.0"; + assertThat(samplingRates[i]).as("Thread %d should have sampling rate %s", i, expectedSamplingRate) + .isEqualTo(expectedSamplingRate); + + coldStartCount += coldStarts[i] ? 1 : 0; + } + assertThat(coldStartCount).isEqualTo(1); + } + + private void reinitializeLogLevel() { + try { + Method initializeLogLevel = PowertoolsLogging.class.getDeclaredMethod("initializeLogLevel"); + initializeLogLevel.setAccessible(true); + initializeLogLevel.invoke(null); + } catch (Exception e) { + throw new RuntimeException("Failed to reinitialize log level", e); + } + } } 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 f77997a77..ca47f9097 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 @@ -31,8 +31,6 @@ import java.io.ByteArrayOutputStream; import java.io.File; import java.io.IOException; -import java.lang.reflect.InvocationTargetException; -import java.lang.reflect.Method; import java.nio.channels.FileChannel; import java.nio.charset.StandardCharsets; import java.nio.file.NoSuchFileException; @@ -41,6 +39,7 @@ import java.util.Collections; import java.util.List; import java.util.Map; +import java.util.concurrent.atomic.AtomicBoolean; import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; @@ -49,8 +48,6 @@ import org.junitpioneer.jupiter.ClearEnvironmentVariable; import org.junitpioneer.jupiter.SetEnvironmentVariable; import org.junitpioneer.jupiter.SetSystemProperty; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; import org.slf4j.MDC; import org.slf4j.event.Level; import org.slf4j.test.TestLogger; @@ -67,6 +64,7 @@ import software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor; import software.amazon.lambda.powertools.common.stubs.TestLambdaContext; +import software.amazon.lambda.powertools.logging.PowertoolsLogging; import software.amazon.lambda.powertools.logging.argument.StructuredArgument; import software.amazon.lambda.powertools.logging.handlers.PowertoolsLogAlbCorrelationId; import software.amazon.lambda.powertools.logging.handlers.PowertoolsLogApiGatewayHttpApiCorrelationId; @@ -90,7 +88,6 @@ class LambdaLoggingAspectTest { - private static final Logger LOG = LoggerFactory.getLogger(LambdaLoggingAspectTest.class); private static final int EXPECTED_CONTEXT_SIZE = 8; private RequestStreamHandler requestStreamHandler; private RequestHandler requestHandler; @@ -98,13 +95,16 @@ class LambdaLoggingAspectTest { private Context context; @BeforeEach - void setUp() throws IllegalAccessException, NoSuchMethodException, InvocationTargetException, IOException { + void setUp() throws IllegalAccessException, IOException { MDC.clear(); + + // Reset cold start state writeStaticField(LambdaHandlerProcessor.class, "isColdStart", null, true); + writeStaticField(PowertoolsLogging.class, "hasBeenInitialized", new AtomicBoolean(false), true); + context = new TestLambdaContext(); requestHandler = new PowertoolsLogEnabled(); requestStreamHandler = new PowertoolsLogEnabledForStream(); - resetLogLevel(Level.INFO); writeStaticField(LoggingConstants.class, "LAMBDA_LOG_LEVEL", null, true); writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", null, true); writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_EVENT", false, true); @@ -131,139 +131,10 @@ void cleanUp() throws IOException { } catch (NoSuchFileException e) { // may not be there in the first run } - } - - @Test - void shouldLogDebugWhenPowertoolsLevelEnvVarIsDebug() throws IllegalAccessException { - // GIVEN - writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", "DEBUG", true); - - // WHEN - LambdaLoggingAspect.setLogLevel(); - - // THEN - assertThat(LOG.isDebugEnabled()).isTrue(); - } - - @Test - void shouldLogInfoWhenPowertoolsLevelEnvVarIsInfo() throws IllegalAccessException { - // GIVEN - writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", "INFO", true); - - // WHEN - LambdaLoggingAspect.setLogLevel(); - - // THEN - assertThat(LOG.isDebugEnabled()).isFalse(); - assertThat(LOG.isInfoEnabled()).isTrue(); - } - - @Test - void shouldLogInfoWhenPowertoolsLevelEnvVarIsInvalid() throws IllegalAccessException { - // GIVEN - writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", "INVALID", true); - - // WHEN - LambdaLoggingAspect.setLogLevel(); - - // THEN - assertThat(LOG.isDebugEnabled()).isFalse(); - assertThat(LOG.isInfoEnabled()).isTrue(); - } - - @Test - void shouldLogWarnWhenPowertoolsLevelEnvVarIsWarn() throws IllegalAccessException { - // GIVEN - writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", "WARN", true); - - // WHEN - LambdaLoggingAspect.setLogLevel(); - - // THEN - assertThat(LOG.isDebugEnabled()).isFalse(); - assertThat(LOG.isInfoEnabled()).isFalse(); - assertThat(LOG.isWarnEnabled()).isTrue(); - } - - @Test - void shouldLogErrorWhenPowertoolsLevelEnvVarIsError() throws IllegalAccessException { - // GIVEN - writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", "ERROR", true); - - // WHEN - LambdaLoggingAspect.setLogLevel(); - // THEN - assertThat(LOG.isDebugEnabled()).isFalse(); - assertThat(LOG.isInfoEnabled()).isFalse(); - assertThat(LOG.isWarnEnabled()).isFalse(); - assertThat(LOG.isErrorEnabled()).isTrue(); - } - - @Test - void shouldLogErrorWhenPowertoolsLevelEnvVarIsFatal() throws IllegalAccessException { - // GIVEN - writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", "FATAL", true); - - // WHEN - LambdaLoggingAspect.setLogLevel(); - - // THEN - assertThat(LOG.isDebugEnabled()).isFalse(); - assertThat(LOG.isInfoEnabled()).isFalse(); - assertThat(LOG.isWarnEnabled()).isFalse(); - assertThat(LOG.isErrorEnabled()).isTrue(); - } - - @Test - void shouldLogWarnWhenPowertoolsLevelEnvVarIsWarnAndLambdaLevelVarIsInfo() throws IllegalAccessException { - // GIVEN - writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", "WARN", true); - writeStaticField(LoggingConstants.class, "LAMBDA_LOG_LEVEL", "INFO", true); - - // WHEN - LambdaLoggingAspect.setLogLevel(); - - // THEN - assertThat(LOG.isDebugEnabled()).isFalse(); - assertThat(LOG.isInfoEnabled()).isFalse(); - assertThat(LOG.isWarnEnabled()).isTrue(); - File logFile = new File("target/logfile.json"); - assertThat(contentOf(logFile)) - .doesNotContain(" does not match AWS Lambda Advanced Logging Controls minimum log level"); - } - - @Test - void shouldLogInfoWhenPowertoolsLevelEnvVarIsInfoAndLambdaLevelVarIsWarn() throws IllegalAccessException { - // GIVEN - writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", "INFO", true); - writeStaticField(LoggingConstants.class, "LAMBDA_LOG_LEVEL", "WARN", true); - - // WHEN - LambdaLoggingAspect.setLogLevel(); - - // THEN - assertThat(LOG.isDebugEnabled()).isFalse(); - assertThat(LOG.isInfoEnabled()).isTrue(); - File logFile = new File("target/logfile.json"); - // should log a warning as powertools level is lower than lambda level - assertThat(contentOf(logFile)).contains( - "Current log level (INFO) does not match AWS Lambda Advanced Logging Controls minimum log level (WARN). This can lead to data loss, consider adjusting them."); - } - - @Test - void shouldLogWarnWhenPowertoolsLevelEnvVarINotSetAndLambdaLevelVarIsWarn() throws IllegalAccessException { - // GIVEN - writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", null, true); - writeStaticField(LoggingConstants.class, "LAMBDA_LOG_LEVEL", "WARN", true); - - // WHEN - LambdaLoggingAspect.setLogLevel(); - - // THEN - assertThat(LOG.isDebugEnabled()).isFalse(); - assertThat(LOG.isInfoEnabled()).isFalse(); - assertThat(LOG.isWarnEnabled()).isTrue(); + // Reset log level to INFO to ensure test isolation + LoggingManager loggingManager = LoggingManagerRegistry.getLoggingManager(); + loggingManager.setLogLevel(Level.INFO); } @Test @@ -855,11 +726,4 @@ void shouldClearBufferBeforeErrorLoggingWhenFlushBufferOnUncaughtErrorDisabled() } } - private void resetLogLevel(Level level) - throws NoSuchMethodException, IllegalAccessException, InvocationTargetException { - Method setLogLevels = LambdaLoggingAspect.class.getDeclaredMethod("setLogLevels", Level.class); - setLogLevels.setAccessible(true); - setLogLevels.invoke(null, level); - writeStaticField(LambdaLoggingAspect.class, "LEVEL_AT_INITIALISATION", level, true); - } } diff --git a/spotbugs-exclude.xml b/spotbugs-exclude.xml index 35aed5e26..53226e3c2 100644 --- a/spotbugs-exclude.xml +++ b/spotbugs-exclude.xml @@ -201,8 +201,7 @@ - - +