diff --git a/.github/pmd-ruleset.xml b/.github/pmd-ruleset.xml index b93fa19b8..1bc5f3020 100644 --- a/.github/pmd-ruleset.xml +++ b/.github/pmd-ruleset.xml @@ -350,6 +350,9 @@ 1 + + + @@ -641,4 +644,4 @@ - \ No newline at end of file + diff --git a/docs/core/logging.md b/docs/core/logging.md index 2d9e57dda..be3bd7e5c 100644 --- a/docs/core/logging.md +++ b/docs/core/logging.md @@ -12,6 +12,7 @@ Logging provides an opinionated logger with output structured as JSON. * Optionally logs Lambda request * Optionally logs Lambda response * Optionally supports log sampling by including a configurable percentage of DEBUG logs in logging output +* Optionally supports buffering lower level logs and flushing them on error or manually * Allows additional keys to be appended to the structured log at any point in time * GraalVM support @@ -311,9 +312,8 @@ We prioritise log level settings in this order: If you set `POWERTOOLS_LOG_LEVEL` lower than ALC, we will emit a warning informing you that your messages will be discarded by Lambda. -> **NOTE** -> -> With ALC enabled, we are unable to increase the minimum log level below the `AWS_LAMBDA_LOG_LEVEL` environment variable value, see [AWS Lambda service documentation](https://docs.aws.amazon.com/lambda/latest/dg/monitoring-cloudwatchlogs.html#monitoring-cloudwatchlogs-log-level){target="_blank"} for more details. +!!! note + With ALC enabled, we are unable to increase the minimum log level below the `AWS_LAMBDA_LOG_LEVEL` environment variable value, see [AWS Lambda service documentation](https://docs.aws.amazon.com/lambda/latest/dg/monitoring-cloudwatchlogs.html#monitoring-cloudwatchlogs-log-level){target="_blank"} for more details. ## Basic Usage @@ -787,7 +787,377 @@ with `logError` param or via `POWERTOOLS_LOGGER_LOG_ERROR` env var. } ``` -# Advanced +## Advanced + +### Buffering logs + +Log buffering enables you to buffer logs for a specific request or invocation. Enable log buffering by configuring the `BufferingAppender` in your logging configuration. You can buffer logs at the `WARNING`, `INFO` or `DEBUG` level, and flush them automatically on error or manually as needed. + +!!! tip "This is useful when you want to reduce the number of log messages emitted while still having detailed logs when needed, such as when troubleshooting issues." + +=== "log4j2.xml" + + ```xml hl_lines="7-12 16 19" + + + + + + + + + + + + + + + + + + + + ``` + +=== "logback.xml" + + ```xml hl_lines="6-11 13 16" + + + + + + + 20480 + DEBUG + true + + + + + + + + + + ``` + +=== "PaymentFunction.java" + + ```java hl_lines="8 12" + import org.slf4j.Logger; + import org.slf4j.LoggerFactory; + import software.amazon.lambda.powertools.logging.Logging; + // ... other imports + + public class PaymentFunction implements RequestHandler { + + private static final Logger LOGGER = LoggerFactory.getLogger(PaymentFunction.class); + + @Logging + public APIGatewayProxyResponseEvent handleRequest(final APIGatewayProxyRequestEvent input, final Context context) { + LOGGER.debug("a debug log"); // this is buffered + LOGGER.info("an info log"); // this is not buffered + + // do stuff + + // Buffer is automatically cleared at the end of the method by @Logging annotation + return new APIGatewayProxyResponseEvent().withStatusCode(200); + } + } + ``` + +#### Configuring the buffer + +When configuring log buffering, you have options to fine-tune how logs are captured, stored, and emitted. You can configure the following parameters in the `BufferingAppender` configuration: + +| Parameter | Description | Configuration | +| --------------------- | ----------------------------------------------- | ---------------------------- | +| `maxBytes` | Maximum size of the log buffer in bytes | `int` (default: 20480 bytes) | +| `bufferAtVerbosity` | Minimum log level to buffer | `DEBUG` (default), `INFO`, `WARNING` | +| `flushOnErrorLog` | Automatically flush buffer when `ERROR` or `FATAL` level logs are emitted | `true` (default), `false` | + +!!! warning "Logger Level Configuration" + To use log buffering effectively, you must set your logger levels to the same level as `bufferAtVerbosity` or more verbose for the logging framework to capture and forward logs to the `BufferingAppender`. For example, if you want to buffer `DEBUG` level logs and emit `INFO`+ level logs directly, you must: + + - Set your logger levels to `DEBUG` in your log4j2.xml or logback.xml configuration + - Set `POWERTOOLS_LOG_LEVEL=DEBUG` if using the environment variable (see [Log level](#log-level) section for more details) + + If you want to sample `INFO` and `WARNING` logs but not `DEBUG` logs, set your log level to `INFO` and `bufferAtVerbosity` to `WARNING`. This allows you to define the lower and upper bounds for buffering. All logs with a more severe level than `bufferAtVerbosity` will be emitted directly. + +=== "log4j2.xml - Buffer at WARNING level" + + ```xml hl_lines="9 14-15 18" + + + + + + + + + + + + + + + + + + + + + ``` + +=== "PaymentFunction.java - Buffer at WARNING level" + + ```java hl_lines="7-9 13" + public class PaymentFunction implements RequestHandler { + + private static final Logger LOGGER = LoggerFactory.getLogger(PaymentFunction.class); + + @Logging + public APIGatewayProxyResponseEvent handleRequest(final APIGatewayProxyRequestEvent input, final Context context) { + LOGGER.warn("a warning log"); // this is buffered + LOGGER.info("an info log"); // this is buffered + LOGGER.debug("a debug log"); // this is buffered + + // do stuff + + // Buffer is automatically cleared at the end of the method by @Logging annotation + return new APIGatewayProxyResponseEvent().withStatusCode(200); + } + } + ``` + +=== "log4j2.xml - Disable flush on error" + + ```xml hl_lines="9" + + + + + + + + + + + + + + + + + + + + ``` + +=== "PaymentFunction.java - Manual flush required" + + ```java hl_lines="1 16 19-20" + import software.amazon.lambda.powertools.logging.PowertoolsLogging; + + public class PaymentFunction implements RequestHandler { + + private static final Logger LOGGER = LoggerFactory.getLogger(PaymentFunction.class); + + @Logging + public APIGatewayProxyResponseEvent handleRequest(final APIGatewayProxyRequestEvent input, final Context context) { + LOGGER.debug("a debug log"); // this is buffered + + // do stuff + + try { + throw new RuntimeException("Something went wrong"); + } catch (RuntimeException error) { + LOGGER.error("An error occurred", error); // Logs won't be flushed here + } + + // Manually flush buffered logs + PowertoolsLogging.flushBuffer(); + + return new APIGatewayProxyResponseEvent().withStatusCode(200); + } + } + ``` + +!!! note "Disabling `flushOnErrorLog` will not flush the buffer when logging an error. This is useful when you want to control when the buffer is flushed by calling the flush method manually." + +#### Manual buffer control + +You can manually control the log buffer using the `PowertoolsLogging` utility class, which provides a backend-independent API that works with both Log4j2 and Logback: + +=== "Manual flush" + + ```java hl_lines="1 12-13" + import software.amazon.lambda.powertools.logging.PowertoolsLogging; + + public class PaymentFunction implements RequestHandler { + + private static final Logger LOGGER = LoggerFactory.getLogger(PaymentFunction.class); + + @Logging + public APIGatewayProxyResponseEvent handleRequest(final APIGatewayProxyRequestEvent input, final Context context) { + LOGGER.debug("Processing payment"); // this is buffered + LOGGER.info("Payment validation complete"); // this is buffered + + // Manually flush all buffered logs + PowertoolsLogging.flushBuffer(); + + return new APIGatewayProxyResponseEvent().withStatusCode(200); + } + } + ``` + +=== "Manual clear" + + ```java hl_lines="1 12-13" + import software.amazon.lambda.powertools.logging.PowertoolsLogging; + + public class PaymentFunction implements RequestHandler { + + private static final Logger LOGGER = LoggerFactory.getLogger(PaymentFunction.class); + + @Logging + public APIGatewayProxyResponseEvent handleRequest(final APIGatewayProxyRequestEvent input, final Context context) { + LOGGER.debug("Processing payment"); // this is buffered + LOGGER.info("Payment validation complete"); // this is buffered + + // Manually clear buffered logs without outputting them + PowertoolsLogging.clearBuffer(); + + return new APIGatewayProxyResponseEvent().withStatusCode(200); + } + } + ``` + +**Available methods:** + +- `#!java PowertoolsLogging.flushBuffer()` - Outputs all buffered logs and clears the buffer +- `#!java PowertoolsLogging.clearBuffer()` - Discards all buffered logs without outputting them + +#### Flushing on exceptions + +Use the `@Logging` annotation to automatically flush buffered logs when an uncaught exception is raised in your Lambda function. This is enabled by default (`flushBufferOnUncaughtError = true`), but you can explicitly configure it if needed. + +=== "PaymentFunction.java" + + ```java hl_lines="5 11" + public class PaymentFunction implements RequestHandler { + + private static final Logger LOGGER = LoggerFactory.getLogger(PaymentFunction.class); + + @Logging(flushBufferOnUncaughtError = true) + public APIGatewayProxyResponseEvent handleRequest(final APIGatewayProxyRequestEvent input, final Context context) { + LOGGER.debug("a debug log"); // this is buffered + + // do stuff + + throw new RuntimeException("Something went wrong"); // Logs will be flushed here + } + } + ``` + +#### Buffering workflows + +##### Manual flush + +
+```mermaid +sequenceDiagram + participant Client + participant Lambda + participant Logger + participant CloudWatch + Client->>Lambda: Invoke Lambda + Lambda->>Logger: Initialize with DEBUG level buffering + Logger-->>Lambda: Logger buffer ready + Lambda->>Logger: logger.debug("First debug log") + Logger-->>Logger: Buffer first debug log + Lambda->>Logger: logger.info("Info log") + Logger->>CloudWatch: Directly log info message + Lambda->>Logger: logger.debug("Second debug log") + Logger-->>Logger: Buffer second debug log + Lambda->>Logger: Manual flush call + Logger->>CloudWatch: Emit buffered logs to stdout + Lambda->>Client: Return execution result +``` +Flushing buffer manually +
+ +##### Flushing when logging an error + +
+```mermaid +sequenceDiagram + participant Client + participant Lambda + participant Logger + participant CloudWatch + Client->>Lambda: Invoke Lambda + Lambda->>Logger: Initialize with DEBUG level buffering + Logger-->>Lambda: Logger buffer ready + Lambda->>Logger: logger.debug("First log") + Logger-->>Logger: Buffer first debug log + Lambda->>Logger: logger.debug("Second log") + Logger-->>Logger: Buffer second debug log + Lambda->>Logger: logger.debug("Third log") + Logger-->>Logger: Buffer third debug log + Lambda->>Lambda: Exception occurs + Lambda->>Logger: logger.error("Error details") + Logger->>CloudWatch: Emit error log + Logger->>CloudWatch: Emit buffered debug logs + Lambda->>Client: Raise exception +``` +Flushing buffer when an error happens +
+ +##### Flushing on exception + +This works when using the `@Logging` annotation which automatically clears the buffer at the end of method execution. + +
+```mermaid +sequenceDiagram + participant Client + participant Lambda + participant Logger + participant CloudWatch + Client->>Lambda: Invoke Lambda + Lambda->>Logger: Using @Logging annotation + Logger-->>Lambda: Logger context injected + Lambda->>Logger: logger.debug("First log") + Logger-->>Logger: Buffer first debug log + Lambda->>Logger: logger.debug("Second log") + Logger-->>Logger: Buffer second debug log + Lambda->>Lambda: Uncaught Exception + Lambda->>CloudWatch: Automatically emit buffered debug logs + Lambda->>Client: Raise uncaught exception +``` +Flushing buffer when an uncaught exception happens +
+ +#### Buffering FAQs + +1. **Does the buffer persist across Lambda invocations?** No, each Lambda invocation has its own buffer. The buffer is initialized when the Lambda function is invoked and is cleared after the function execution completes or when flushed manually. +2. **Are my logs buffered during cold starts (INIT phase)?** No, we never buffer logs during cold starts. This is because we want to ensure that logs emitted during this phase are always available for debugging and monitoring purposes. The buffer is only used during the execution of the Lambda function. +3. **How can I prevent log buffering from consuming excessive memory?** You can limit the size of the buffer by setting the `maxBytes` option in the `BufferingAppender` configuration. This will ensure that the buffer does not grow indefinitely. +4. **What happens if the log buffer reaches its maximum size?** Older logs are removed from the buffer to make room for new logs. This means that if the buffer is full, you may lose some logs if they are not flushed before the buffer reaches its maximum size. When this happens, we emit a warning when flushing the buffer to indicate that some logs have been dropped. +5. **How is the log size of a log line calculated?** The log size is calculated based on the size of the log line in bytes. This includes the size of the log message, any exception (if present), the log line location, additional keys, and the timestamp. +6. **What timestamp is used when I flush the logs?** The timestamp is the original time when the log record was created. If you create a log record at 11:00:10 and flush it at 11:00:25, the log line will retain its original timestamp of 11:00:10. +7. **What happens if I try to add a log line that is bigger than max buffer size?** The log will be emitted directly to standard output and not buffered. When this happens, we emit a warning to indicate that the log line was too big to be buffered. +8. **What happens if Lambda times out without flushing the buffer?** Logs that are still in the buffer will be lost. +9. **How does the `BufferingAppender` work with different appenders?** The `BufferingAppender` is designed to wrap arbitrary appenders, providing maximum flexibility. You can wrap console appenders, file appenders, or any custom appenders with buffering functionality. ## Sampling debug logs diff --git a/examples/powertools-examples-core-utilities/sam/src/main/java/helloworld/App.java b/examples/powertools-examples-core-utilities/sam/src/main/java/helloworld/App.java index 2675c96eb..2844e50fe 100644 --- a/examples/powertools-examples-core-utilities/sam/src/main/java/helloworld/App.java +++ b/examples/powertools-examples-core-utilities/sam/src/main/java/helloworld/App.java @@ -97,11 +97,6 @@ public APIGatewayProxyResponseEvent handleRequest(final APIGatewayProxyRequestEv } } - @Tracing - private void log() { - log.info("inside threaded logging for function"); - } - @Tracing(namespace = "getPageContents", captureMode = CaptureMode.DISABLED) private String getPageContents(String address) throws IOException { URL url = new URL(address); diff --git a/examples/powertools-examples-core-utilities/sam/src/main/java/helloworld/AppStream.java b/examples/powertools-examples-core-utilities/sam/src/main/java/helloworld/AppStream.java index 8bc57b201..d3ebbef5d 100644 --- a/examples/powertools-examples-core-utilities/sam/src/main/java/helloworld/AppStream.java +++ b/examples/powertools-examples-core-utilities/sam/src/main/java/helloworld/AppStream.java @@ -14,41 +14,45 @@ package helloworld; -import com.amazonaws.services.lambda.runtime.Context; -import com.amazonaws.services.lambda.runtime.RequestStreamHandler; -import com.fasterxml.jackson.databind.ObjectMapper; - +import java.io.BufferedReader; +import java.io.BufferedWriter; import java.io.IOException; import java.io.InputStream; +import java.io.InputStreamReader; import java.io.OutputStream; +import java.io.OutputStreamWriter; +import java.io.PrintWriter; import java.nio.charset.StandardCharsets; -import org.apache.logging.log4j.LogManager; -import org.apache.logging.log4j.Logger; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import com.amazonaws.services.lambda.runtime.Context; +import com.amazonaws.services.lambda.runtime.RequestStreamHandler; +import com.fasterxml.jackson.databind.ObjectMapper; + import software.amazon.lambda.powertools.logging.Logging; import software.amazon.lambda.powertools.metrics.FlushMetrics; -import java.io.InputStreamReader; -import java.io.BufferedReader; -import java.io.BufferedWriter; -import java.io.OutputStreamWriter; -import java.io.PrintWriter; - public class AppStream implements RequestStreamHandler { private static final ObjectMapper mapper = new ObjectMapper(); - private final static Logger log = LogManager.getLogger(AppStream.class); + private static final Logger log = LoggerFactory.getLogger(AppStream.class); @Override @Logging(logEvent = true) @FlushMetrics(namespace = "ServerlessAirline", service = "payment", captureColdStart = true) - // RequestStreamHandler can be used instead of RequestHandler for cases when you'd like to deserialize request body or serialize response body yourself, instead of allowing that to happen automatically - // Note that you still need to return a proper JSON for API Gateway to handle - // See Lambda Response format for examples: https://docs.aws.amazon.com/apigateway/latest/developerguide/http-api-develop-integrations-lambda.html + // RequestStreamHandler can be used instead of RequestHandler for cases when you'd like to deserialize request body + // or serialize response body yourself, instead of allowing that to happen automatically + // Note that you still need to return a proper JSON for API Gateway to handle + // See Lambda Response format for examples: + // https://docs.aws.amazon.com/apigateway/latest/developerguide/http-api-develop-integrations-lambda.html public void handleRequest(InputStream input, OutputStream output, Context context) { try (BufferedReader reader = new BufferedReader(new InputStreamReader(input, StandardCharsets.UTF_8)); - PrintWriter writer = new PrintWriter(new BufferedWriter(new OutputStreamWriter(output, StandardCharsets.UTF_8)))) { + PrintWriter writer = new PrintWriter( + new BufferedWriter(new OutputStreamWriter(output, StandardCharsets.UTF_8)))) { - log.info("Received: " + mapper.writerWithDefaultPrettyPrinter().writeValueAsString(mapper.readTree(reader))); + log.info( + "Received: " + mapper.writerWithDefaultPrettyPrinter().writeValueAsString(mapper.readTree(reader))); writer.write("{\"body\": \"" + System.currentTimeMillis() + "\"} "); } catch (IOException e) { @@ -56,4 +60,3 @@ public void handleRequest(InputStream input, OutputStream output, Context contex } } } - diff --git a/examples/powertools-examples-core-utilities/sam/src/main/resources/log4j2.xml b/examples/powertools-examples-core-utilities/sam/src/main/resources/log4j2.xml index e1fd14cea..e140022e4 100644 --- a/examples/powertools-examples-core-utilities/sam/src/main/resources/log4j2.xml +++ b/examples/powertools-examples-core-utilities/sam/src/main/resources/log4j2.xml @@ -4,13 +4,13 @@ + + + - - - - - + + - \ No newline at end of file + diff --git a/examples/powertools-examples-core-utilities/sam/template.yaml b/examples/powertools-examples-core-utilities/sam/template.yaml index 9a51a1ba9..6b1814dce 100644 --- a/examples/powertools-examples-core-utilities/sam/template.yaml +++ b/examples/powertools-examples-core-utilities/sam/template.yaml @@ -1,4 +1,4 @@ -AWSTemplateFormatVersion: '2010-09-09' +AWSTemplateFormatVersion: "2010-09-09" Transform: AWS::Serverless-2016-10-31 Description: > CoreUtilities @@ -13,7 +13,7 @@ Globals: Environment: Variables: # Powertools for AWS Lambda (Java) env vars: https://docs.powertools.aws.dev/lambda/java/#environment-variables - POWERTOOLS_LOG_LEVEL: INFO + POWERTOOLS_LOG_LEVEL: DEBUG # We use log buffering to buffer DEBUG logs (see log4j2.xml) POWERTOOLS_LOGGER_SAMPLE_RATE: 0.1 POWERTOOLS_LOGGER_LOG_EVENT: true POWERTOOLS_METRICS_NAMESPACE: Coreutilities diff --git a/powertools-e2e-tests/handlers/logging/pom.xml b/powertools-e2e-tests/handlers/logging-log4j/pom.xml similarity index 90% rename from powertools-e2e-tests/handlers/logging/pom.xml rename to powertools-e2e-tests/handlers/logging-log4j/pom.xml index f8b5689c8..d415ae4b3 100644 --- a/powertools-e2e-tests/handlers/logging/pom.xml +++ b/powertools-e2e-tests/handlers/logging-log4j/pom.xml @@ -8,20 +8,15 @@ 2.3.0 - e2e-test-handler-logging + e2e-test-handler-logging-log4j jar - E2E test handler – Logging + E2E test handler – Logging Log4j software.amazon.lambda powertools-logging-log4j - - org.apache.logging.log4j - log4j-layout-template-json - 2.25.1 - org.aspectj aspectjrt diff --git a/powertools-e2e-tests/handlers/logging/src/main/java/software/amazon/lambda/powertools/e2e/Function.java b/powertools-e2e-tests/handlers/logging-log4j/src/main/java/software/amazon/lambda/powertools/e2e/Function.java similarity index 86% rename from powertools-e2e-tests/handlers/logging/src/main/java/software/amazon/lambda/powertools/e2e/Function.java rename to powertools-e2e-tests/handlers/logging-log4j/src/main/java/software/amazon/lambda/powertools/e2e/Function.java index 58492653a..94520c447 100644 --- a/powertools-e2e-tests/handlers/logging/src/main/java/software/amazon/lambda/powertools/e2e/Function.java +++ b/powertools-e2e-tests/handlers/logging-log4j/src/main/java/software/amazon/lambda/powertools/e2e/Function.java @@ -14,12 +14,15 @@ package software.amazon.lambda.powertools.e2e; -import com.amazonaws.services.lambda.runtime.Context; -import com.amazonaws.services.lambda.runtime.RequestHandler; 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); @@ -29,6 +32,9 @@ public String handleRequest(Input input, Context 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"; } -} \ No newline at end of file +} diff --git a/powertools-e2e-tests/handlers/logging/src/main/java/software/amazon/lambda/powertools/e2e/Input.java b/powertools-e2e-tests/handlers/logging-log4j/src/main/java/software/amazon/lambda/powertools/e2e/Input.java similarity index 97% rename from powertools-e2e-tests/handlers/logging/src/main/java/software/amazon/lambda/powertools/e2e/Input.java rename to powertools-e2e-tests/handlers/logging-log4j/src/main/java/software/amazon/lambda/powertools/e2e/Input.java index cc449922e..66fd49ddc 100644 --- a/powertools-e2e-tests/handlers/logging/src/main/java/software/amazon/lambda/powertools/e2e/Input.java +++ b/powertools-e2e-tests/handlers/logging-log4j/src/main/java/software/amazon/lambda/powertools/e2e/Input.java @@ -20,9 +20,6 @@ public class Input { private String message; private Map keys; - public Input() { - } - public String getMessage() { return message; } diff --git a/powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-core/reflect-config.json b/powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-core/reflect-config.json similarity index 100% rename from powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-core/reflect-config.json rename to powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-core/reflect-config.json diff --git a/powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-events/reflect-config.json b/powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-events/reflect-config.json similarity index 100% rename from powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-events/reflect-config.json rename to powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-events/reflect-config.json diff --git a/powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/jni-config.json b/powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/jni-config.json similarity index 100% rename from powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/jni-config.json rename to powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/jni-config.json diff --git a/powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/native-image.properties b/powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/native-image.properties similarity index 100% rename from powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/native-image.properties rename to powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/native-image.properties diff --git a/powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/reflect-config.json b/powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/reflect-config.json similarity index 100% rename from powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/reflect-config.json rename to powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/reflect-config.json diff --git a/powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/resource-config.json b/powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/resource-config.json similarity index 100% rename from powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/resource-config.json rename to powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/resource-config.json diff --git a/powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-serialization/reflect-config.json b/powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-serialization/reflect-config.json similarity index 100% rename from powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-serialization/reflect-config.json rename to powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-serialization/reflect-config.json diff --git a/powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/reflect-config.json b/powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/reflect-config.json similarity index 100% rename from powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/reflect-config.json rename to powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/reflect-config.json diff --git a/powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/resource-config.json b/powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/resource-config.json similarity index 100% rename from powertools-e2e-tests/handlers/logging/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/resource-config.json rename to powertools-e2e-tests/handlers/logging-log4j/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/resource-config.json diff --git a/powertools-e2e-tests/handlers/logging/src/main/resources/log4j2.xml b/powertools-e2e-tests/handlers/logging-log4j/src/main/resources/log4j2.xml similarity index 52% rename from powertools-e2e-tests/handlers/logging/src/main/resources/log4j2.xml rename to powertools-e2e-tests/handlers/logging-log4j/src/main/resources/log4j2.xml index 8925f70b9..28e03a9e0 100644 --- a/powertools-e2e-tests/handlers/logging/src/main/resources/log4j2.xml +++ b/powertools-e2e-tests/handlers/logging-log4j/src/main/resources/log4j2.xml @@ -4,13 +4,14 @@ + + + + - + - - - - \ No newline at end of file + diff --git a/powertools-e2e-tests/handlers/logging-logback/pom.xml b/powertools-e2e-tests/handlers/logging-logback/pom.xml new file mode 100644 index 000000000..932eb0612 --- /dev/null +++ b/powertools-e2e-tests/handlers/logging-logback/pom.xml @@ -0,0 +1,82 @@ + + 4.0.0 + + + software.amazon.lambda + e2e-test-handlers-parent + 2.3.0 + + + e2e-test-handler-logging-logback + jar + E2E test handler – Logging Logback + + + + software.amazon.lambda + powertools-logging-logback + + + org.aspectj + aspectjrt + + + com.amazonaws + aws-lambda-java-events + + + com.amazonaws + aws-lambda-java-runtime-interface-client + + + com.amazonaws + aws-lambda-java-core + + + + + + + dev.aspectj + aspectj-maven-plugin + + ${maven.compiler.source} + ${maven.compiler.target} + ${maven.compiler.target} + + + software.amazon.lambda + powertools-logging + + + + + + + compile + + + + + + org.apache.maven.plugins + maven-shade-plugin + + + + + + + native-image + + + + org.graalvm.buildtools + native-maven-plugin + + + + + + diff --git a/powertools-e2e-tests/handlers/logging-logback/src/main/java/software/amazon/lambda/powertools/e2e/Function.java b/powertools-e2e-tests/handlers/logging-logback/src/main/java/software/amazon/lambda/powertools/e2e/Function.java new file mode 100644 index 000000000..94520c447 --- /dev/null +++ b/powertools-e2e-tests/handlers/logging-logback/src/main/java/software/amazon/lambda/powertools/e2e/Function.java @@ -0,0 +1,40 @@ +/* + * 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); + + @Logging + public String handleRequest(Input input, Context 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-logback/src/main/java/software/amazon/lambda/powertools/e2e/Input.java b/powertools-e2e-tests/handlers/logging-logback/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-logback/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-logback/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-core/reflect-config.json b/powertools-e2e-tests/handlers/logging-logback/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-logback/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-logback/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-events/reflect-config.json b/powertools-e2e-tests/handlers/logging-logback/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-logback/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-logback/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/jni-config.json b/powertools-e2e-tests/handlers/logging-logback/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-logback/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-logback/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/native-image.properties b/powertools-e2e-tests/handlers/logging-logback/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-logback/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-logback/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/reflect-config.json b/powertools-e2e-tests/handlers/logging-logback/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-logback/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-logback/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-runtime-interface-client/resource-config.json b/powertools-e2e-tests/handlers/logging-logback/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-logback/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-logback/src/main/resources/META-INF/native-image/com.amazonaws/aws-lambda-java-serialization/reflect-config.json b/powertools-e2e-tests/handlers/logging-logback/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-logback/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-logback/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/reflect-config.json b/powertools-e2e-tests/handlers/logging-logback/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-logback/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-logback/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/resource-config.json b/powertools-e2e-tests/handlers/logging-logback/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/resource-config.json new file mode 100644 index 000000000..a603a9398 --- /dev/null +++ b/powertools-e2e-tests/handlers/logging-logback/src/main/resources/META-INF/native-image/software.amazon.lambda.powertools.e2e/resource-config.json @@ -0,0 +1,7 @@ +{ + "resources":{ + "includes":[{ + "pattern":"\\Qlogback.xml\\E" + }]}, + "bundles":[] +} diff --git a/powertools-e2e-tests/handlers/logging-logback/src/main/resources/logback.xml b/powertools-e2e-tests/handlers/logging-logback/src/main/resources/logback.xml new file mode 100644 index 000000000..0a5e4d146 --- /dev/null +++ b/powertools-e2e-tests/handlers/logging-logback/src/main/resources/logback.xml @@ -0,0 +1,16 @@ + + + + + + + + + INFO + + + + + + + \ No newline at end of file diff --git a/powertools-e2e-tests/handlers/metrics/src/main/java/software/amazon/lambda/powertools/e2e/Input.java b/powertools-e2e-tests/handlers/metrics/src/main/java/software/amazon/lambda/powertools/e2e/Input.java index 1328ded77..054c2867a 100644 --- a/powertools-e2e-tests/handlers/metrics/src/main/java/software/amazon/lambda/powertools/e2e/Input.java +++ b/powertools-e2e-tests/handlers/metrics/src/main/java/software/amazon/lambda/powertools/e2e/Input.java @@ -23,9 +23,6 @@ public class Input { private String highResolution; - public Input() { - } - public Map getMetrics() { return metrics; } diff --git a/powertools-e2e-tests/handlers/pom.xml b/powertools-e2e-tests/handlers/pom.xml index ffe44eb8e..c4afd58f4 100644 --- a/powertools-e2e-tests/handlers/pom.xml +++ b/powertools-e2e-tests/handlers/pom.xml @@ -28,7 +28,8 @@ batch largemessage largemessage_idempotent - logging + logging-log4j + logging-logback tracing metrics idempotency @@ -56,6 +57,11 @@ powertools-logging-log4j ${project.version} + + software.amazon.lambda + powertools-logging-logback + ${project.version} + software.amazon.lambda powertools-tracing diff --git a/powertools-e2e-tests/handlers/tracing/src/main/java/software/amazon/lambda/powertools/e2e/Input.java b/powertools-e2e-tests/handlers/tracing/src/main/java/software/amazon/lambda/powertools/e2e/Input.java index 92078d0b3..ed89f4498 100644 --- a/powertools-e2e-tests/handlers/tracing/src/main/java/software/amazon/lambda/powertools/e2e/Input.java +++ b/powertools-e2e-tests/handlers/tracing/src/main/java/software/amazon/lambda/powertools/e2e/Input.java @@ -17,9 +17,6 @@ public class Input { private String message; - public Input() { - } - public String getMessage() { return message; } diff --git a/powertools-e2e-tests/pom.xml b/powertools-e2e-tests/pom.xml index 4094bfb20..d206697c9 100644 --- a/powertools-e2e-tests/pom.xml +++ b/powertools-e2e-tests/pom.xml @@ -102,6 +102,11 @@ junit-jupiter-engine test + + org.junit.jupiter + junit-jupiter-params + test + org.assertj assertj-core 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 ad2c2564f..f5d2cea84 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 @@ -25,10 +25,11 @@ import java.util.stream.Collectors; import java.util.stream.Stream; -import org.junit.jupiter.api.AfterAll; -import org.junit.jupiter.api.BeforeAll; -import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.TestInstance; import org.junit.jupiter.api.Timeout; +import org.junit.jupiter.params.ParameterizedTest; +import org.junit.jupiter.params.provider.ValueSource; import com.fasterxml.jackson.core.JsonProcessingException; import com.fasterxml.jackson.databind.JsonNode; @@ -37,20 +38,19 @@ import software.amazon.lambda.powertools.testutils.Infrastructure; import software.amazon.lambda.powertools.testutils.lambda.InvocationResult; +@TestInstance(TestInstance.Lifecycle.PER_CLASS) class LoggingE2ET { private static final ObjectMapper objectMapper = new ObjectMapper(); - private static Infrastructure infrastructure; - private static String functionName; + private Infrastructure infrastructure; + private String functionName; - @BeforeAll - @Timeout(value = 10, unit = TimeUnit.MINUTES) - static void setup() { + private void setupInfrastructure(String pathToFunction) { infrastructure = Infrastructure.builder() - .testName(LoggingE2ET.class.getSimpleName()) + .testName(LoggingE2ET.class.getSimpleName() + "-" + pathToFunction) .tracing(true) - .pathToFunction("logging") + .pathToFunction(pathToFunction) .environmentVariables( Stream.of(new String[][] { { "POWERTOOLS_LOG_LEVEL", "INFO" }, @@ -62,15 +62,19 @@ static void setup() { functionName = outputs.get(FUNCTION_NAME_OUTPUT); } - @AfterAll - static void tearDown() { + @AfterEach + void tearDown() { if (infrastructure != null) { infrastructure.destroy(); } } - @Test - void test_logInfoWithAdditionalKeys() throws JsonProcessingException { + @ParameterizedTest + @ValueSource(strings = { "logging-log4j", "logging-logback" }) + @Timeout(value = 15, unit = TimeUnit.MINUTES) + void test_logInfoWithAdditionalKeys(String pathToFunction) throws JsonProcessingException { + setupInfrastructure(pathToFunction); + // GIVEN String orderId = UUID.randomUUID().toString(); String event = "{\"message\":\"New Order\", \"keys\":{\"orderId\":\"" + orderId + "\"}}"; diff --git a/powertools-logging/powertools-logging-log4j/src/main/java/software/amazon/lambda/powertools/logging/log4j/BufferingAppender.java b/powertools-logging/powertools-logging-log4j/src/main/java/software/amazon/lambda/powertools/logging/log4j/BufferingAppender.java new file mode 100644 index 000000000..fcf4a2040 --- /dev/null +++ b/powertools-logging/powertools-logging-log4j/src/main/java/software/amazon/lambda/powertools/logging/log4j/BufferingAppender.java @@ -0,0 +1,201 @@ +/* + * 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.log4j; + +import java.io.Serializable; +import java.util.Deque; + +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.core.Appender; +import org.apache.logging.log4j.core.Core; +import org.apache.logging.log4j.core.Filter; +import org.apache.logging.log4j.core.Layout; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.appender.AbstractAppender; +import org.apache.logging.log4j.core.config.AppenderRef; +import org.apache.logging.log4j.core.config.Configuration; +import org.apache.logging.log4j.core.config.plugins.Plugin; +import org.apache.logging.log4j.core.config.plugins.PluginAttribute; +import org.apache.logging.log4j.core.config.plugins.PluginConfiguration; +import org.apache.logging.log4j.core.config.plugins.PluginElement; +import org.apache.logging.log4j.core.config.plugins.PluginFactory; +import org.apache.logging.log4j.core.impl.Log4jLogEvent; +import org.apache.logging.log4j.message.SimpleMessage; + +import software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor; +import software.amazon.lambda.powertools.logging.internal.BufferManager; +import software.amazon.lambda.powertools.logging.internal.KeyBuffer; + +/** + * A Log4j2 appender that buffers log events by AWS X-Ray trace ID for optimized Lambda logging. + * + *

This appender is designed specifically for AWS Lambda functions to reduce log ingestion + * by buffering lower-level logs and only outputting them when errors occur, preserving + * full context for troubleshooting while minimizing routine log volume. + * + *

Key Features:

+ *
    + *
  • Trace-based buffering: Groups logs by AWS X-Ray trace ID
    • + *
  • Selective output: Only buffers logs at or below configured verbosity level
    • + *
  • Auto-flush on errors: Automatically outputs buffered logs when ERROR/FATAL events occur
    • + *
  • Memory management: Prevents memory leaks with configurable buffer size limits
    • + *
  • Overflow protection: Warns when logs are discarded due to buffer limits
    • + *
+ * + *

Configuration Example:

+ * 
{@code
+ * 
+ *   
+ * 
+ * }
+ * + *

Configuration Parameters:

+ *
    + *
  • bufferAtVerbosity: Log level to buffer (default: DEBUG). Logs at this level and below are buffered
    • + *
  • maxBytes: Maximum buffer size in bytes per trace ID (default: 20480)
    • + *
  • flushOnErrorLog: Whether to flush buffer on ERROR/FATAL logs (default: true)
    • + *
+ * + *

Behavior:

+ *
    + *
  • During Lambda INIT phase (no trace ID): logs are output directly
    • + *
  • During Lambda execution (with trace ID): logs are buffered or output based on level
    • + *
  • When buffer overflows: oldest logs are discarded and a warning is logged
    • + *
  • On Lambda completion: buffer is auto-cleared when used with {@code @Logging} annotation
    • + *
+ * + * @see software.amazon.lambda.powertools.logging.PowertoolsLogging#flushBuffer() + */ +@Plugin(name = "BufferingAppender", category = Core.CATEGORY_NAME, elementType = Appender.ELEMENT_TYPE) +public class BufferingAppender extends AbstractAppender implements BufferManager { + + private final AppenderRef[] appenderRefs; + private final Configuration configuration; + private final Level bufferAtVerbosity; + private final boolean flushOnErrorLog; + private final KeyBuffer buffer; + + @SuppressWarnings("java:S107") // Constructor has too many parameters, which is OK for a Log4j2 plugin + protected BufferingAppender(String name, Filter filter, Layout layout, + AppenderRef[] appenderRefs, Configuration configuration, Level bufferAtVerbosity, int maxBytes, + boolean flushOnErrorLog) { + super(name, filter, layout, false, null); + this.appenderRefs = appenderRefs; + this.configuration = configuration; + this.bufferAtVerbosity = bufferAtVerbosity; + this.flushOnErrorLog = flushOnErrorLog; + this.buffer = new KeyBuffer<>(maxBytes, event -> event.getMessage().getFormattedMessage().length(), + this::logOverflowWarning); + } + + @Override + public void append(LogEvent event) { + if (appenderRefs == null || appenderRefs.length == 0) { + return; + } + + LambdaHandlerProcessor.getXrayTraceId().ifPresentOrElse( + traceId -> { + if (shouldBuffer(event.getLevel())) { + bufferEvent(traceId, event); + } else { + callAppenders(event); + } + + // Flush buffer on error logs if configured + if (flushOnErrorLog && event.getLevel().isMoreSpecificThan(Level.WARN)) { + flushBuffer(traceId); + } + }, + () -> callAppenders(event) // No trace ID (INIT phase), log directly + ); + } + + private void callAppenders(LogEvent event) { + for (AppenderRef ref : appenderRefs) { + Appender appender = configuration.getAppender(ref.getRef()); + if (appender != null) { + appender.append(event); + } + } + } + + private boolean shouldBuffer(Level level) { + return level.isLessSpecificThan(bufferAtVerbosity) || level.equals(bufferAtVerbosity); + } + + private void bufferEvent(String traceId, LogEvent event) { + LogEvent immutableEvent = Log4jLogEvent.createMemento(event); + buffer.add(traceId, immutableEvent); + } + + public void clearBuffer() { + LambdaHandlerProcessor.getXrayTraceId().ifPresent(buffer::clear); + } + + public void flushBuffer() { + LambdaHandlerProcessor.getXrayTraceId().ifPresent(this::flushBuffer); + } + + private void flushBuffer(String traceId) { + Deque events = buffer.removeAll(traceId); + if (events != null) { + events.forEach(this::callAppenders); + } + } + + @PluginFactory + @SuppressWarnings("java:S107") // Method has too many parameters, which is OK for a Log4j2 plugin factory + public static BufferingAppender createAppender( + @PluginAttribute("name") String name, + @PluginElement("Filter") Filter filter, + @PluginElement("Layout") Layout layout, + @PluginElement("AppenderRef") AppenderRef[] appenderRefs, + @PluginConfiguration Configuration configuration, + @PluginAttribute(value = "bufferAtVerbosity", defaultString = "DEBUG") String bufferAtVerbosity, + @PluginAttribute(value = "maxBytes", defaultInt = 20480) int maxBytes, + @PluginAttribute(value = "flushOnErrorLog", defaultBoolean = true) boolean flushOnErrorLog) { + + if (name == null) { + LOGGER.error("No name provided for BufferingAppender"); + return null; + } + + Level level = Level.getLevel(bufferAtVerbosity); + if (level == null) { + level = Level.DEBUG; + } + + return new BufferingAppender(name, filter, layout, appenderRefs, configuration, level, maxBytes, + flushOnErrorLog); + } + + private void logOverflowWarning() { + // Create a properly formatted warning event and send directly to child appenders. Used to avoid circular + // dependency between KeyBuffer and BufferingAppender. + SimpleMessage message = new SimpleMessage( + "Some logs are not displayed because they were evicted from the buffer. Increase buffer size to store more logs in the buffer."); + LogEvent warningEvent = Log4jLogEvent.newBuilder() + .setLoggerName(BufferingAppender.class.getName()) + .setLevel(Level.WARN) + .setMessage(message) + .setTimeMillis(System.currentTimeMillis()) + .build(); + callAppenders(warningEvent); + } +} diff --git a/powertools-logging/powertools-logging-log4j/src/main/java/software/amazon/lambda/powertools/logging/log4/internal/Log4jLoggingManager.java b/powertools-logging/powertools-logging-log4j/src/main/java/software/amazon/lambda/powertools/logging/log4j/internal/Log4jLoggingManager.java similarity index 54% rename from powertools-logging/powertools-logging-log4j/src/main/java/software/amazon/lambda/powertools/logging/log4/internal/Log4jLoggingManager.java rename to powertools-logging/powertools-logging-log4j/src/main/java/software/amazon/lambda/powertools/logging/log4j/internal/Log4jLoggingManager.java index 4e57a8e45..90bbe1d32 100644 --- a/powertools-logging/powertools-logging-log4j/src/main/java/software/amazon/lambda/powertools/logging/log4/internal/Log4jLoggingManager.java +++ b/powertools-logging/powertools-logging-log4j/src/main/java/software/amazon/lambda/powertools/logging/log4j/internal/Log4jLoggingManager.java @@ -12,19 +12,26 @@ * */ -package software.amazon.lambda.powertools.logging.log4.internal; +package software.amazon.lambda.powertools.logging.log4j.internal; + +import java.util.Collection; +import java.util.stream.Collectors; import org.apache.logging.log4j.Level; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.core.LoggerContext; import org.apache.logging.log4j.core.config.Configurator; import org.slf4j.Logger; + +import software.amazon.lambda.powertools.logging.internal.BufferManager; import software.amazon.lambda.powertools.logging.internal.LoggingManager; +import software.amazon.lambda.powertools.logging.log4j.BufferingAppender; /** - * LoggingManager for Log4j2 (see {@link LoggingManager}). + * LoggingManager for Log4j2 that provides log level management and buffer operations. + * Implements both {@link LoggingManager} and {@link BufferManager} interfaces. */ -public class Log4jLoggingManager implements LoggingManager { +public class Log4jLoggingManager implements LoggingManager, BufferManager { /** * @inheritDoc @@ -45,4 +52,29 @@ public org.slf4j.event.Level getLogLevel(Logger logger) { LoggerContext ctx = (LoggerContext) LogManager.getContext(false); return org.slf4j.event.Level.valueOf(ctx.getLogger(logger.getName()).getLevel().toString()); } + + /** + * @inheritDoc + */ + @Override + public void flushBuffer() { + getBufferingAppenders().forEach(BufferingAppender::flushBuffer); + } + + /** + * @inheritDoc + */ + @Override + public void clearBuffer() { + getBufferingAppenders().forEach(BufferingAppender::clearBuffer); + } + + private Collection getBufferingAppenders() { + // Search all buffering appenders to avoid relying on the appender name given by the user + LoggerContext ctx = (LoggerContext) LogManager.getContext(false); + return ctx.getConfiguration().getAppenders().values().stream() + .filter(BufferingAppender.class::isInstance) + .map(BufferingAppender.class::cast) + .collect(Collectors.toList()); + } } diff --git a/powertools-logging/powertools-logging-log4j/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-log4j/jni-config.json b/powertools-logging/powertools-logging-log4j/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-log4j/jni-config.json index 2c4de0562..c8b081385 100644 --- a/powertools-logging/powertools-logging-log4j/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-log4j/jni-config.json +++ b/powertools-logging/powertools-logging-log4j/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-log4j/jni-config.json @@ -3,22 +3,6 @@ "name":"java.lang.Boolean", "methods":[{"name":"getBoolean","parameterTypes":["java.lang.String"] }] }, -{ - "name":"java.lang.String", - "methods":[{"name":"lastIndexOf","parameterTypes":["int"] }, {"name":"substring","parameterTypes":["int"] }] -}, -{ - "name":"java.lang.System", - "methods":[{"name":"getProperty","parameterTypes":["java.lang.String"] }, {"name":"setProperty","parameterTypes":["java.lang.String","java.lang.String"] }] -}, -{ - "name":"org.apache.maven.surefire.booter.ForkedBooter", - "methods":[{"name":"main","parameterTypes":["java.lang.String[]"] }] -}, -{ - "name":"sun.instrument.InstrumentationImpl", - "methods":[{"name":"","parameterTypes":["long","boolean","boolean","boolean"] }, {"name":"loadClassAndCallAgentmain","parameterTypes":["java.lang.String","java.lang.String"] }, {"name":"loadClassAndCallPremain","parameterTypes":["java.lang.String","java.lang.String"] }, {"name":"transform","parameterTypes":["java.lang.Module","java.lang.ClassLoader","java.lang.String","java.lang.Class","java.security.ProtectionDomain","byte[]","boolean"] }] -}, { "name":"sun.management.VMManagementImpl", "fields":[{"name":"compTimeMonitoringSupport"}, {"name":"currentThreadCpuTimeSupport"}, {"name":"objectMonitorUsageSupport"}, {"name":"otherThreadCpuTimeSupport"}, {"name":"remoteDiagnosticCommandsSupport"}, {"name":"synchronizerUsageSupport"}, {"name":"threadAllocatedMemorySupport"}, {"name":"threadContentionMonitoringSupport"}] diff --git a/powertools-logging/powertools-logging-log4j/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-log4j/reflect-config.json b/powertools-logging/powertools-logging-log4j/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-log4j/reflect-config.json index 9b2afe183..adbd9e0c1 100644 --- a/powertools-logging/powertools-logging-log4j/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-log4j/reflect-config.json +++ b/powertools-logging/powertools-logging-log4j/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-log4j/reflect-config.json @@ -1,4 +1,10 @@ [ +{ + "name":"[Ljava.lang.Object;" +}, +{ + "name":"[Ljava.lang.String;" +}, { "name":"[Lorg.apache.logging.log4j.core.Appender;" }, @@ -15,16 +21,7 @@ "name":"[Lorg.apache.logging.log4j.layout.template.json.JsonTemplateLayout$EventTemplateAdditionalField;" }, { - "name":"com.amazonaws.services.lambda.runtime.Context", - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "queryAllDeclaredConstructors":true, - "methods":[{"name":"getAwsRequestId","parameterTypes":[] }, {"name":"getClientContext","parameterTypes":[] }, {"name":"getFunctionName","parameterTypes":[] }, {"name":"getFunctionVersion","parameterTypes":[] }, {"name":"getIdentity","parameterTypes":[] }, {"name":"getInvokedFunctionArn","parameterTypes":[] }, {"name":"getLogGroupName","parameterTypes":[] }, {"name":"getLogStreamName","parameterTypes":[] }, {"name":"getLogger","parameterTypes":[] }, {"name":"getMemoryLimitInMB","parameterTypes":[] }, {"name":"getRemainingTimeInMillis","parameterTypes":[] }] -}, -{ - "name":"com.amazonaws.services.lambda.runtime.RequestHandler", - "allDeclaredClasses":true, - "queryAllPublicMethods":true + "name":"com.amazonaws.services.lambda.runtime.Context" }, { "name":"com.amazonaws.services.lambda.runtime.events.SQSEvent$MessageAttribute", @@ -60,155 +57,88 @@ "name":"com.sun.org.apache.xerces.internal.jaxp.DocumentBuilderFactoryImpl", "methods":[{"name":"","parameterTypes":[] }] }, -{ - "name":"com.sun.tools.attach.VirtualMachine" -}, { "name":"jakarta.servlet.Servlet" }, { "name":"java.io.Serializable", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "queryAllDeclaredConstructors":true -}, -{ - "name":"java.lang.Class", - "methods":[{"name":"forName","parameterTypes":["java.lang.String"] }, {"name":"getAnnotatedInterfaces","parameterTypes":[] }, {"name":"getAnnotatedSuperclass","parameterTypes":[] }, {"name":"getDeclaredMethod","parameterTypes":["java.lang.String","java.lang.Class[]"] }, {"name":"getMethod","parameterTypes":["java.lang.String","java.lang.Class[]"] }, {"name":"getModule","parameterTypes":[] }, {"name":"getNestHost","parameterTypes":[] }, {"name":"getNestMembers","parameterTypes":[] }, {"name":"getPermittedSubclasses","parameterTypes":[] }, {"name":"getRecordComponents","parameterTypes":[] }, {"name":"isNestmateOf","parameterTypes":["java.lang.Class"] }, {"name":"isRecord","parameterTypes":[] }, {"name":"isSealed","parameterTypes":[] }] -}, -{ - "name":"java.lang.ClassLoader", - "methods":[{"name":"getDefinedPackage","parameterTypes":["java.lang.String"] }, {"name":"getUnnamedModule","parameterTypes":[] }, {"name":"registerAsParallelCapable","parameterTypes":[] }] + "queryAllDeclaredMethods":true }, { "name":"java.lang.Cloneable", "queryAllDeclaredMethods":true }, { - "name":"java.lang.Comparable", - "allDeclaredClasses":true, - "queryAllPublicMethods":true -}, -{ - "name":"java.lang.Enum", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"java.lang.Module", - "methods":[{"name":"addExports","parameterTypes":["java.lang.String","java.lang.Module"] }, {"name":"addReads","parameterTypes":["java.lang.Module"] }, {"name":"canRead","parameterTypes":["java.lang.Module"] }, {"name":"getClassLoader","parameterTypes":[] }, {"name":"getName","parameterTypes":[] }, {"name":"getPackages","parameterTypes":[] }, {"name":"getResourceAsStream","parameterTypes":["java.lang.String"] }, {"name":"isExported","parameterTypes":["java.lang.String"] }, {"name":"isExported","parameterTypes":["java.lang.String","java.lang.Module"] }, {"name":"isNamed","parameterTypes":[] }, {"name":"isOpen","parameterTypes":["java.lang.String","java.lang.Module"] }] + "name":"java.lang.Iterable", + "queryAllDeclaredMethods":true }, { "name":"java.lang.Object", - "allDeclaredFields":true, - "queryAllDeclaredMethods":true, - "queryAllDeclaredConstructors":true, - "methods":[{"name":"","parameterTypes":[] }, {"name":"clone","parameterTypes":[] }, {"name":"getClass","parameterTypes":[] }, {"name":"toString","parameterTypes":[] }] + "allDeclaredFields":true }, { "name":"java.lang.ProcessEnvironment", "fields":[{"name":"theCaseInsensitiveEnvironment"}, {"name":"theEnvironment"}] }, -{ - "name":"java.lang.ProcessHandle", - "methods":[{"name":"current","parameterTypes":[] }, {"name":"pid","parameterTypes":[] }] -}, -{ - "name":"java.lang.Runtime", - "methods":[{"name":"version","parameterTypes":[] }] -}, -{ - "name":"java.lang.Runtime$Version", - "methods":[{"name":"feature","parameterTypes":[] }] -}, -{ - "name":"java.lang.StackWalker" -}, { "name":"java.lang.String" }, -{ - "name":"java.lang.System", - "methods":[{"name":"getSecurityManager","parameterTypes":[] }] -}, { "name":"java.lang.Thread", "fields":[{"name":"threadLocalRandomProbe"}] }, { - "name":"java.lang.annotation.Retention", - "queryAllDeclaredMethods":true, - "queryAllDeclaredConstructors":true -}, -{ - "name":"java.lang.annotation.Target", - "queryAllDeclaredMethods":true, - "queryAllDeclaredConstructors":true -}, -{ - "name":"java.lang.constant.Constable", - "allDeclaredClasses":true, - "queryAllPublicMethods":true -}, -{ - "name":"java.lang.invoke.MethodHandle", - "methods":[{"name":"bindTo","parameterTypes":["java.lang.Object"] }, {"name":"invokeWithArguments","parameterTypes":["java.lang.Object[]"] }] -}, -{ - "name":"java.lang.invoke.MethodHandles", - "methods":[{"name":"lookup","parameterTypes":[] }] -}, -{ - "name":"java.lang.invoke.MethodHandles$Lookup", - "methods":[{"name":"findVirtual","parameterTypes":["java.lang.Class","java.lang.String","java.lang.invoke.MethodType"] }] -}, -{ - "name":"java.lang.invoke.MethodType", - "methods":[{"name":"methodType","parameterTypes":["java.lang.Class","java.lang.Class[]"] }] + "name":"java.sql.Date" }, { - "name":"java.lang.reflect.AccessibleObject", - "methods":[{"name":"setAccessible","parameterTypes":["boolean"] }] + "name":"java.sql.Time" }, { - "name":"java.lang.reflect.AnnotatedArrayType", - "methods":[{"name":"getAnnotatedGenericComponentType","parameterTypes":[] }] + "name":"java.util.AbstractCollection", + "allDeclaredFields":true, + "queryAllDeclaredMethods":true }, { - "name":"java.lang.reflect.AnnotatedType", - "methods":[{"name":"getType","parameterTypes":[] }] + "name":"java.util.AbstractList", + "allDeclaredFields":true, + "queryAllDeclaredMethods":true }, { - "name":"java.lang.reflect.Executable", - "methods":[{"name":"getAnnotatedExceptionTypes","parameterTypes":[] }, {"name":"getAnnotatedParameterTypes","parameterTypes":[] }, {"name":"getAnnotatedReceiverType","parameterTypes":[] }, {"name":"getParameterCount","parameterTypes":[] }, {"name":"getParameters","parameterTypes":[] }] + "name":"java.util.AbstractMap", + "allDeclaredFields":true, + "queryAllDeclaredMethods":true }, { - "name":"java.lang.reflect.Method", - "methods":[{"name":"getAnnotatedReturnType","parameterTypes":[] }] + "name":"java.util.Arrays$ArrayList", + "allDeclaredFields":true, + "queryAllDeclaredMethods":true, + "queryAllDeclaredConstructors":true }, { - "name":"java.lang.reflect.Parameter", - "methods":[{"name":"getModifiers","parameterTypes":[] }, {"name":"getName","parameterTypes":[] }, {"name":"isNamePresent","parameterTypes":[] }] + "name":"java.util.Collection", + "queryAllDeclaredMethods":true }, { - "name":"java.security.AccessController", - "methods":[{"name":"doPrivileged","parameterTypes":["java.security.PrivilegedAction"] }, {"name":"doPrivileged","parameterTypes":["java.security.PrivilegedExceptionAction"] }] + "name":"java.util.Collections$SingletonMap", + "allDeclaredFields":true, + "queryAllDeclaredMethods":true, + "queryAllDeclaredConstructors":true }, { - "name":"java.sql.Date" + "name":"java.util.Collections$UnmodifiableMap", + "fields":[{"name":"m"}] }, { - "name":"java.sql.Time" + "name":"java.util.List", + "queryAllDeclaredMethods":true }, { - "name":"java.util.Collections$UnmodifiableMap", - "fields":[{"name":"m"}] + "name":"java.util.Map", + "queryAllDeclaredMethods":true }, { - "name":"java.util.concurrent.ForkJoinTask", - "fields":[{"name":"aux"}, {"name":"status"}] + "name":"java.util.RandomAccess", + "queryAllDeclaredMethods":true }, { "name":"java.util.concurrent.atomic.AtomicBoolean", @@ -230,10 +160,7 @@ "name":"javax.servlet.Servlet" }, { - "name":"jdk.internal.misc.Unsafe" -}, -{ - "name":"kotlin.jvm.JvmInline" + "name":"kotlin.Metadata" }, { "name":"org.apache.logging.log4j.core.appender.AbstractAppender$Builder", @@ -493,6 +420,12 @@ "queryAllDeclaredMethods":true, "methods":[{"name":"createLoggers","parameterTypes":["org.apache.logging.log4j.core.config.LoggerConfig[]"] }] }, +{ + "name":"org.apache.logging.log4j.core.config.MonitorResource" +}, +{ + "name":"org.apache.logging.log4j.core.config.MonitorResources" +}, { "name":"org.apache.logging.log4j.core.config.PropertiesPlugin" }, @@ -743,7 +676,13 @@ "name":"org.apache.logging.log4j.core.layout.MessageLayout" }, { - "name":"org.apache.logging.log4j.core.layout.PatternLayout" + "name":"org.apache.logging.log4j.core.layout.PatternLayout", + "queryAllDeclaredMethods":true, + "methods":[{"name":"newBuilder","parameterTypes":[] }] +}, +{ + "name":"org.apache.logging.log4j.core.layout.PatternLayout$Builder", + "allDeclaredFields":true }, { "name":"org.apache.logging.log4j.core.layout.PatternMatch" @@ -878,9 +817,7 @@ "name":"org.apache.logging.log4j.core.pattern.ClassNamePatternConverter" }, { - "name":"org.apache.logging.log4j.core.pattern.DatePatternConverter", - "queryAllDeclaredMethods":true, - "methods":[{"name":"newInstance","parameterTypes":["java.lang.String[]"] }] + "name":"org.apache.logging.log4j.core.pattern.DatePatternConverter" }, { "name":"org.apache.logging.log4j.core.pattern.EncodingPatternConverter" @@ -913,9 +850,7 @@ "name":"org.apache.logging.log4j.core.pattern.IntegerPatternConverter" }, { - "name":"org.apache.logging.log4j.core.pattern.LevelPatternConverter", - "queryAllDeclaredMethods":true, - "methods":[{"name":"newInstance","parameterTypes":["java.lang.String[]"] }] + "name":"org.apache.logging.log4j.core.pattern.LevelPatternConverter" }, { "name":"org.apache.logging.log4j.core.pattern.LineLocationPatternConverter" @@ -929,9 +864,7 @@ "name":"org.apache.logging.log4j.core.pattern.LoggerFqcnPatternConverter" }, { - "name":"org.apache.logging.log4j.core.pattern.LoggerPatternConverter", - "queryAllDeclaredMethods":true, - "methods":[{"name":"newInstance","parameterTypes":["java.lang.String[]"] }] + "name":"org.apache.logging.log4j.core.pattern.LoggerPatternConverter" }, { "name":"org.apache.logging.log4j.core.pattern.MapPatternConverter" @@ -990,9 +923,7 @@ "name":"org.apache.logging.log4j.core.pattern.ThreadIdPatternConverter" }, { - "name":"org.apache.logging.log4j.core.pattern.ThreadNamePatternConverter", - "queryAllDeclaredMethods":true, - "methods":[{"name":"newInstance","parameterTypes":["java.lang.String[]"] }] + "name":"org.apache.logging.log4j.core.pattern.ThreadNamePatternConverter" }, { "name":"org.apache.logging.log4j.core.pattern.ThreadPriorityPatternConverter" @@ -1105,29 +1036,6 @@ "queryAllDeclaredMethods":true, "methods":[{"name":"getInstance","parameterTypes":[] }] }, -{ - "name":"org.apache.logging.log4j.layout.template.json.resolver.PowerToolsResolverFactoryTest", - "allDeclaredFields":true, - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "queryAllDeclaredConstructors":true, - "methods":[{"name":"","parameterTypes":[] }, {"name":"cleanUp","parameterTypes":[] }, {"name":"setUp","parameterTypes":[] }, {"name":"shouldLogInEcsFormat","parameterTypes":[] }, {"name":"shouldLogInJsonFormat","parameterTypes":[] }] -}, -{ - "name":"org.apache.logging.log4j.layout.template.json.resolver.PowertoolsResolverArgumentsTest", - "allDeclaredFields":true, - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "queryAllDeclaredConstructors":true, - "methods":[{"name":"","parameterTypes":[] }, {"name":"cleanUp","parameterTypes":[] }, {"name":"setUp","parameterTypes":[] }, {"name":"shouldLogArgumentsAsJsonWhenUsingKeyValue","parameterTypes":[] }, {"name":"shouldLogArgumentsAsJsonWhenUsingRawJson","parameterTypes":[] }] -}, -{ - "name":"org.apache.logging.log4j.layout.template.json.resolver.PowertoolsResolverFactory", - "queryAllDeclaredMethods":true, - "methods":[{"name":"getInstance","parameterTypes":[] }] -}, { "name":"org.apache.logging.log4j.layout.template.json.resolver.SourceResolverFactory", "queryAllDeclaredMethods":true, @@ -1161,12 +1069,6 @@ "name":"org.apiguardian.api.API", "queryAllPublicMethods":true }, -{ - "name":"org.aspectj.runtime.internal.AroundClosure", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, { "name":"org.jctools.queues.MpmcArrayQueue" }, @@ -1178,48 +1080,8 @@ "fields":[{"name":"IS_COLD_START"}] }, { - "name":"software.amazon.lambda.powertools.logging.internal.Log4jLoggingManagerTest", - "allDeclaredFields":true, - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "queryAllDeclaredConstructors":true, - "methods":[{"name":"","parameterTypes":[] }, {"name":"getLogLevel_shouldReturnConfiguredLogLevel","parameterTypes":[] }, {"name":"resetLogLevel","parameterTypes":[] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.internal.handler.PowertoolsArguments", - "allDeclaredClasses":true, + "name":"software.amazon.lambda.powertools.logging.log4j.BufferingAppender", "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"handleRequest","parameterTypes":["com.amazonaws.services.lambda.runtime.events.SQSEvent$SQSMessage","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.internal.handler.PowertoolsArguments$AjcClosure1", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.internal.handler.PowertoolsArguments$ArgumentFormat", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.internal.handler.PowertoolsLogEnabled", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"handleRequest","parameterTypes":["java.lang.Object","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.internal.handler.PowertoolsLogEnabled$AjcClosure1", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"sun.reflect.ReflectionFactory", - "methods":[{"name":"getReflectionFactory","parameterTypes":[] }, {"name":"newConstructorForSerialization","parameterTypes":["java.lang.Class","java.lang.reflect.Constructor"] }] + "methods":[{"name":"createAppender","parameterTypes":["java.lang.String","org.apache.logging.log4j.core.Filter","org.apache.logging.log4j.core.Layout","org.apache.logging.log4j.core.config.AppenderRef[]","org.apache.logging.log4j.core.config.Configuration","java.lang.String","int","boolean"] }] } ] diff --git a/powertools-logging/powertools-logging-log4j/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-log4j/resource-config.json b/powertools-logging/powertools-logging-log4j/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-log4j/resource-config.json index aca0e0356..cf017fdeb 100644 --- a/powertools-logging/powertools-logging-log4j/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-log4j/resource-config.json +++ b/powertools-logging/powertools-logging-log4j/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-log4j/resource-config.json @@ -12,8 +12,6 @@ "pattern":"\\QMETA-INF/services/java.lang.System$LoggerFinder\\E" }, { "pattern":"\\QMETA-INF/services/java.net.spi.InetAddressResolverProvider\\E" - }, { - "pattern":"\\QMETA-INF/services/java.time.zone.ZoneRulesProvider\\E" }, { "pattern":"\\QMETA-INF/services/javax.xml.parsers.DocumentBuilderFactory\\E" }, { @@ -36,60 +34,6 @@ "pattern":"\\QMETA-INF/services/software.amazon.lambda.powertools.logging.internal.LoggingManager\\E" }, { "pattern":"\\QStackTraceElementLayout.json\\E" - }, { - "pattern":"\\Qlog4j2-test.jsn\\E" - }, { - "pattern":"\\Qlog4j2-test.json\\E" - }, { - "pattern":"\\Qlog4j2-test.properties\\E" - }, { - "pattern":"\\Qlog4j2-test.xml\\E" - }, { - "pattern":"\\Qlog4j2-test.yaml\\E" - }, { - "pattern":"\\Qlog4j2-test.yml\\E" - }, { - "pattern":"\\Qlog4j2-test18b4aac2.jsn\\E" - }, { - "pattern":"\\Qlog4j2-test18b4aac2.json\\E" - }, { - "pattern":"\\Qlog4j2-test18b4aac2.properties\\E" - }, { - "pattern":"\\Qlog4j2-test18b4aac2.xml\\E" - }, { - "pattern":"\\Qlog4j2-test18b4aac2.yaml\\E" - }, { - "pattern":"\\Qlog4j2-test18b4aac2.yml\\E" - }, { - "pattern":"\\Qlog4j2.StatusLogger.properties\\E" - }, { - "pattern":"\\Qlog4j2.component.properties\\E" - }, { - "pattern":"\\Qlog4j2.jsn\\E" - }, { - "pattern":"\\Qlog4j2.json\\E" - }, { - "pattern":"\\Qlog4j2.properties\\E" - }, { - "pattern":"\\Qlog4j2.system.properties\\E" - }, { - "pattern":"\\Qlog4j2.xml\\E" - }, { - "pattern":"\\Qlog4j2.yaml\\E" - }, { - "pattern":"\\Qlog4j2.yml\\E" - }, { - "pattern":"\\Qlog4j218b4aac2.jsn\\E" - }, { - "pattern":"\\Qlog4j218b4aac2.json\\E" - }, { - "pattern":"\\Qlog4j218b4aac2.properties\\E" - }, { - "pattern":"\\Qlog4j218b4aac2.xml\\E" - }, { - "pattern":"\\Qlog4j218b4aac2.yaml\\E" - }, { - "pattern":"\\Qlog4j218b4aac2.yml\\E" }]}, "bundles":[] } diff --git a/powertools-logging/powertools-logging-log4j/src/main/resources/META-INF/services/software.amazon.lambda.powertools.logging.internal.LoggingManager b/powertools-logging/powertools-logging-log4j/src/main/resources/META-INF/services/software.amazon.lambda.powertools.logging.internal.LoggingManager index d444c5525..d4b2a72a0 100644 --- a/powertools-logging/powertools-logging-log4j/src/main/resources/META-INF/services/software.amazon.lambda.powertools.logging.internal.LoggingManager +++ b/powertools-logging/powertools-logging-log4j/src/main/resources/META-INF/services/software.amazon.lambda.powertools.logging.internal.LoggingManager @@ -1 +1 @@ -software.amazon.lambda.powertools.logging.log4.internal.Log4jLoggingManager \ No newline at end of file +software.amazon.lambda.powertools.logging.log4j.internal.Log4jLoggingManager diff --git a/powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/internal/Log4jLoggingManagerTest.java b/powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/internal/Log4jLoggingManagerTest.java deleted file mode 100644 index 69e1ee710..000000000 --- a/powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/internal/Log4jLoggingManagerTest.java +++ /dev/null @@ -1,51 +0,0 @@ -package software.amazon.lambda.powertools.logging.internal; - -import static org.assertj.core.api.Assertions.assertThat; -import static org.slf4j.event.Level.DEBUG; -import static org.slf4j.event.Level.ERROR; -import static org.slf4j.event.Level.WARN; - -import org.junit.jupiter.api.Order; -import org.junit.jupiter.api.Test; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; -import org.slf4j.event.Level; -import software.amazon.lambda.powertools.logging.log4.internal.Log4jLoggingManager; - -class Log4jLoggingManagerTest { - - private final static Logger LOG = LoggerFactory.getLogger(Log4jLoggingManagerTest.class); - private final static Logger ROOT = LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME); - - @Test - @Order(1) - void getLogLevel_shouldReturnConfiguredLogLevel() { - // Given log4j2.xml in resources - - // When - Log4jLoggingManager manager = new Log4jLoggingManager(); - Level logLevel = manager.getLogLevel(LOG); - Level rootLevel = manager.getLogLevel(ROOT); - - // Then - assertThat(logLevel).isEqualTo(DEBUG); - assertThat(rootLevel).isEqualTo(WARN); - } - - @Test - @Order(2) - void resetLogLevel() { - // Given log4j2.xml in resources - - // When - Log4jLoggingManager manager = new Log4jLoggingManager(); - manager.setLogLevel(ERROR); - - Level rootLevel = manager.getLogLevel(ROOT); - Level logLevel = manager.getLogLevel(LOG); - - // Then - assertThat(rootLevel).isEqualTo(ERROR); - assertThat(logLevel).isEqualTo(ERROR); - } -} diff --git a/powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/internal/handler/PowertoolsArguments.java b/powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/internal/handler/PowertoolsArguments.java index 1fc235ff7..0d95f29fa 100644 --- a/powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/internal/handler/PowertoolsArguments.java +++ b/powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/internal/handler/PowertoolsArguments.java @@ -34,7 +34,7 @@ import software.amazon.lambda.powertools.utilities.JsonConfig; public class PowertoolsArguments implements RequestHandler { - private final Logger LOG = LoggerFactory.getLogger(PowertoolsArguments.class); + private static final Logger LOG = LoggerFactory.getLogger(PowertoolsArguments.class); private final ArgumentFormat argumentFormat; public PowertoolsArguments(ArgumentFormat argumentFormat) { diff --git a/powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/internal/handler/PowertoolsLogEnabled.java b/powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/internal/handler/PowertoolsLogEnabled.java index e8c0c5851..0ee7f14fa 100644 --- a/powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/internal/handler/PowertoolsLogEnabled.java +++ b/powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/internal/handler/PowertoolsLogEnabled.java @@ -14,15 +14,17 @@ package software.amazon.lambda.powertools.logging.internal.handler; -import com.amazonaws.services.lambda.runtime.Context; -import com.amazonaws.services.lambda.runtime.RequestHandler; 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; public class PowertoolsLogEnabled implements RequestHandler { - private final Logger LOG = LoggerFactory.getLogger(PowertoolsLogEnabled.class); + private static final Logger LOG = LoggerFactory.getLogger(PowertoolsLogEnabled.class); @Override @Logging(clearState = true) diff --git a/powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/log4j/BufferingAppenderTest.java b/powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/log4j/BufferingAppenderTest.java new file mode 100644 index 000000000..434d3983b --- /dev/null +++ b/powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/log4j/BufferingAppenderTest.java @@ -0,0 +1,141 @@ +package software.amazon.lambda.powertools.logging.log4j; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.assertj.core.api.Assertions.contentOf; + +import java.io.File; +import java.io.IOException; +import java.nio.channels.FileChannel; +import java.nio.file.NoSuchFileException; +import java.nio.file.Paths; +import java.nio.file.StandardOpenOption; + +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.Appender; +import org.apache.logging.log4j.core.LoggerContext; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; +import org.junitpioneer.jupiter.ClearEnvironmentVariable; + +class BufferingAppenderTest { + + private Logger logger; + + @BeforeEach + void setUp() throws IOException { + logger = LogManager.getLogger(BufferingAppenderTest.class); + + 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 { + FileChannel.open(Paths.get("target/logfile.json"), StandardOpenOption.WRITE).truncate(0).close(); + } + + @Test + void shouldBufferDebugLogsAndFlushOnError() { + // When - log debug messages (should be buffered) + logger.debug("Debug message 1"); + logger.debug("Debug message 2"); + + // Then - no logs written yet + File logFile = new File("target/logfile.json"); + assertThat(contentOf(logFile)).isEmpty(); + + // When - log error (should flush buffer) + logger.error("Error message"); + + // Then - all logs written + assertThat(contentOf(logFile)) + .contains("Debug message 1") + .contains("Debug message 2") + .contains("Error message"); + } + + @Test + @ClearEnvironmentVariable(key = "_X_AMZN_TRACE_ID") + void shouldLogDirectlyWhenNoTraceId() { + // When + logger.debug("Debug without trace"); + + // Then - log written directly + File logFile = new File("target/logfile.json"); + assertThat(contentOf(logFile)).contains("Debug without trace"); + } + + @Test + void shouldNotBufferInfoLogs() { + // When - log info message (above buffer level) + logger.info("Info message"); + + // Then - log written directly + File logFile = new File("target/logfile.json"); + assertThat(contentOf(logFile)).contains("Info message"); + } + + @Test + void shouldFlushBufferManually() { + // When - buffer debug logs + logger.debug("Buffered message"); + File logFile = new File("target/logfile.json"); + assertThat(contentOf(logFile)).isEmpty(); + + // When - manual flush + BufferingAppender appender = getBufferingAppender(); + appender.flushBuffer(); + + // Then - logs written + assertThat(contentOf(logFile)).contains("Buffered message"); + } + + @Test + void shouldClearBufferManually() { + // When - buffer debug logs then clear + logger.debug("Buffered message"); + BufferingAppender appender = getBufferingAppender(); + appender.clearBuffer(); + + // When - log error (should not flush cleared buffer) + logger.error("Error after clear"); + + // Then - only error logged + File logFile = new File("target/logfile.json"); + assertThat(contentOf(logFile)) + .contains("Error after clear") + .doesNotContain("Buffered message"); + } + + @Test + void shouldLogOverflowWarningWhenBufferOverflows() { + // When - fill buffer beyond capacity to trigger overflow + for (int i = 0; i < 100; i++) { + logger.debug("Debug message {}", i); + } + + // When - flush buffer to trigger overflow warning + BufferingAppender appender = getBufferingAppender(); + appender.flushBuffer(); + + // Then - overflow warning should be logged + File logFile = new File("target/logfile.json"); + assertThat(contentOf(logFile)) + .contains("Some logs are not displayed because they were evicted from the buffer"); + } + + private BufferingAppender getBufferingAppender() { + LoggerContext context = (LoggerContext) LogManager.getContext(false); + Appender appender = context.getConfiguration().getAppender("BufferingAppender"); + if (appender == null) { + throw new IllegalStateException("BufferingAppender not found in configuration. Available appenders: " + + context.getConfiguration().getAppenders().keySet()); + } + return (BufferingAppender) appender; + } +} diff --git a/powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/log4j/internal/Log4jLoggingManagerTest.java b/powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/log4j/internal/Log4jLoggingManagerTest.java new file mode 100644 index 000000000..16036fe3e --- /dev/null +++ b/powertools-logging/powertools-logging-log4j/src/test/java/software/amazon/lambda/powertools/logging/log4j/internal/Log4jLoggingManagerTest.java @@ -0,0 +1,118 @@ +package software.amazon.lambda.powertools.logging.log4j.internal; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.assertj.core.api.Assertions.contentOf; +import static org.slf4j.event.Level.DEBUG; +import static org.slf4j.event.Level.ERROR; +import static org.slf4j.event.Level.WARN; + +import java.io.File; +import java.io.IOException; +import java.nio.channels.FileChannel; +import java.nio.file.NoSuchFileException; +import java.nio.file.Paths; +import java.nio.file.StandardOpenOption; + +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.core.LoggerContext; +import org.apache.logging.log4j.core.config.Configuration; +import org.apache.logging.log4j.core.config.ConfigurationFactory; +import org.apache.logging.log4j.core.config.ConfigurationSource; +import org.apache.logging.log4j.core.config.Configurator; +import org.apache.logging.log4j.core.config.xml.XmlConfigurationFactory; +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.event.Level; + +class Log4jLoggingManagerTest { + + private static final Logger LOG = LoggerFactory.getLogger(Log4jLoggingManagerTest.class); + private static final Logger ROOT = LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME); + + @BeforeEach + void setUp() { + // Force reconfiguration from XML to ensure clean state + Configurator.reconfigure(); + } + + @Test + void getLogLevel_shouldReturnConfiguredLogLevel() { + // Given log4j2.xml in resources + + // When + Log4jLoggingManager manager = new Log4jLoggingManager(); + Level logLevel = manager.getLogLevel(LOG); + Level rootLevel = manager.getLogLevel(ROOT); + + // Then + assertThat(logLevel).isEqualTo(DEBUG); + assertThat(rootLevel).isEqualTo(WARN); + } + + @Test + void resetLogLevel() { + // Given log4j2.xml in resources + + // When + Log4jLoggingManager manager = new Log4jLoggingManager(); + manager.setLogLevel(ERROR); + + Level rootLevel = manager.getLogLevel(ROOT); + Level logLevel = manager.getLogLevel(LOG); + + // Then + assertThat(rootLevel).isEqualTo(ERROR); + assertThat(logLevel).isEqualTo(ERROR); + } + + @Test + void shouldDetectMultipleBufferingAppendersRegardlessOfName() throws IOException { + // Given - configuration with multiple BufferingAppenders with different names + try { + FileChannel.open(Paths.get("target/logfile.json"), StandardOpenOption.WRITE).truncate(0).close(); + } catch (NoSuchFileException e) { + // may not be there in the first run + } + + LoggerContext ctx = (LoggerContext) LogManager.getContext(false); + ConfigurationFactory factory = new XmlConfigurationFactory(); + ConfigurationSource source = new ConfigurationSource( + getClass().getResourceAsStream("/log4j2-multiple-buffering.xml")); + Configuration config = factory.getConfiguration(null, source); + + ctx.setConfiguration(config); + ctx.updateLoggers(); + + org.apache.logging.log4j.Logger logger = LogManager.getLogger("test.multiple.appenders"); + + // When - log messages and flush buffers + logger.debug("Test message 1"); + logger.debug("Test message 2"); + + Log4jLoggingManager manager = new Log4jLoggingManager(); + manager.flushBuffer(); + + // Then - both appenders should have flushed their buffers + File logFile = new File("target/logfile.json"); + assertThat(logFile).exists(); + String content = contentOf(logFile); + // Each message should appear twice (once from each BufferingAppender) + assertThat(content.split("Test message 1", -1)).hasSize(3); // 2 occurrences = 3 parts + assertThat(content.split("Test message 2", -1)).hasSize(3); // 2 occurrences = 3 parts + } + + @AfterEach + void cleanUp() throws IOException { + // Reset to original configuration from XML + Configurator.reconfigure(); + + try { + FileChannel.open(Paths.get("target/logfile.json"), StandardOpenOption.WRITE).truncate(0).close(); + } catch (NoSuchFileException e) { + // may not be there + } + } +} diff --git a/powertools-logging/powertools-logging-log4j/src/test/resources/log4j2-multiple-buffering.xml b/powertools-logging/powertools-logging-log4j/src/test/resources/log4j2-multiple-buffering.xml new file mode 100644 index 000000000..53995e4f5 --- /dev/null +++ b/powertools-logging/powertools-logging-log4j/src/test/resources/log4j2-multiple-buffering.xml @@ -0,0 +1,26 @@ + + + + + + + + + + + + + + + + + + + + diff --git a/powertools-logging/powertools-logging-log4j/src/test/resources/log4j2.xml b/powertools-logging/powertools-logging-log4j/src/test/resources/log4j2.xml index 778077bc5..870e3a803 100644 --- a/powertools-logging/powertools-logging-log4j/src/test/resources/log4j2.xml +++ b/powertools-logging/powertools-logging-log4j/src/test/resources/log4j2.xml @@ -10,8 +10,17 @@ + + + - q + + + + diff --git a/powertools-logging/powertools-logging-logback/pom.xml b/powertools-logging/powertools-logging-logback/pom.xml index 433a3774a..e2c16019f 100644 --- a/powertools-logging/powertools-logging-logback/pom.xml +++ b/powertools-logging/powertools-logging-logback/pom.xml @@ -85,6 +85,11 @@ jsonassert test + + org.junit-pioneer + junit-pioneer + test + diff --git a/powertools-logging/powertools-logging-logback/src/main/java/software/amazon/lambda/powertools/logging/logback/BufferingAppender.java b/powertools-logging/powertools-logging-logback/src/main/java/software/amazon/lambda/powertools/logging/logback/BufferingAppender.java new file mode 100644 index 000000000..8f323ff46 --- /dev/null +++ b/powertools-logging/powertools-logging-logback/src/main/java/software/amazon/lambda/powertools/logging/logback/BufferingAppender.java @@ -0,0 +1,196 @@ +/* + * 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.logback; + +import java.util.Deque; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.classic.spi.LoggingEvent; +import ch.qos.logback.core.Appender; +import ch.qos.logback.core.AppenderBase; +import ch.qos.logback.core.spi.AppenderAttachable; +import ch.qos.logback.core.spi.AppenderAttachableImpl; +import software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor; +import software.amazon.lambda.powertools.logging.internal.BufferManager; +import software.amazon.lambda.powertools.logging.internal.KeyBuffer; + +/** + * A Logback appender that buffers log events by AWS X-Ray trace ID for optimized Lambda logging. + * + *

This appender is designed specifically for AWS Lambda functions to reduce log ingestion + * by buffering lower-level logs and only outputting them when errors occur, preserving + * full context for troubleshooting while minimizing routine log volume. + * + *

Key Features:

+ *
    + *
  • Trace-based buffering: Groups logs by AWS X-Ray trace ID
    • + *
  • Selective output: Only buffers logs at or below configured verbosity level
    • + *
  • Auto-flush on errors: Automatically outputs buffered logs when ERROR/FATAL events occur
    • + *
  • Memory management: Prevents memory leaks with configurable buffer size limits
    • + *
  • Overflow protection: Warns when logs are discarded due to buffer limits
    • + *
+ * + *

Configuration Example:

+ * 
{@code
+ * 
+ *   DEBUG
+ *   20480
+ *   true
+ *   
+ * 
+ * }
+ * + *

Configuration Parameters:

+ *
    + *
  • bufferAtVerbosity: Log level to buffer (default: DEBUG). Logs at this level and below are buffered
    • + *
  • maxBytes: Maximum buffer size in bytes per trace ID (default: 20480)
    • + *
  • flushOnErrorLog: Whether to flush buffer on ERROR/FATAL logs (default: true)
    • + *
+ * + *

Behavior:

+ *
    + *
  • During Lambda INIT phase (no trace ID): logs are output directly
    • + *
  • During Lambda execution (with trace ID): logs are buffered or output based on level
    • + *
  • When buffer overflows: oldest logs are discarded and a warning is logged
    • + *
  • On Lambda completion: buffer is auto-cleared when used with {@code @Logging} annotation
    • + *
+ * + * @see software.amazon.lambda.powertools.logging.PowertoolsLogging#flushBuffer() + */ +public class BufferingAppender extends AppenderBase + implements AppenderAttachable, BufferManager { + + private static final int DEFAULT_BUFFER_SIZE = 20480; + + private final AppenderAttachableImpl aai = new AppenderAttachableImpl<>(); + private Level bufferAtVerbosity = Level.DEBUG; + private boolean flushOnErrorLog = true; + private int maxBytes = DEFAULT_BUFFER_SIZE; + private KeyBuffer buffer; + + @Override + public void start() { + // Initialize lazily to ensure configuration properties are set first. + if (buffer == null) { + buffer = new KeyBuffer<>(maxBytes, event -> event.getFormattedMessage().length(), this::logOverflowWarning); + } + super.start(); + } + + @Override + protected void append(ILoggingEvent event) { + LambdaHandlerProcessor.getXrayTraceId().ifPresentOrElse( + traceId -> { + if (shouldBuffer(event.getLevel())) { + buffer.add(traceId, event); + } else { + aai.appendLoopOnAppenders(event); + } + + // Flush buffer on error logs if configured + if (flushOnErrorLog && event.getLevel().isGreaterOrEqual(Level.ERROR)) { + flushBuffer(traceId); + } + }, + () -> aai.appendLoopOnAppenders(event) // No trace ID (INIT phase), log directly + ); + } + + private boolean shouldBuffer(Level level) { + return level.levelInt <= bufferAtVerbosity.levelInt; + } + + public void clearBuffer() { + LambdaHandlerProcessor.getXrayTraceId().ifPresent(buffer::clear); + } + + public void flushBuffer() { + LambdaHandlerProcessor.getXrayTraceId().ifPresent(this::flushBuffer); + } + + private void flushBuffer(String traceId) { + Deque events = buffer.removeAll(traceId); + if (events != null) { + events.forEach(aai::appendLoopOnAppenders); + } + } + + // Configuration setters. These will be inspected as JavaBean properties by Logback + // when configuring the appender via XML or programmatically. They run before start(). + public void setBufferAtVerbosity(String level) { + this.bufferAtVerbosity = Level.toLevel(level, Level.DEBUG); + } + + public void setMaxBytes(int maxBytes) { + this.maxBytes = maxBytes; + } + + public void setFlushOnErrorLog(boolean flushOnErrorLog) { + this.flushOnErrorLog = flushOnErrorLog; + } + + // AppenderAttachable implementation. We simply delegate to the internal logback AppenderAttachableImpl. This is + // needed to be able to attach other appenders to this appender so that customers can wrap existing appenders with + // this buffering appender. + @Override + public void addAppender(Appender newAppender) { + aai.addAppender(newAppender); + } + + @Override + public java.util.Iterator> iteratorForAppenders() { + return aai.iteratorForAppenders(); + } + + @Override + public Appender getAppender(String name) { + return aai.getAppender(name); + } + + @Override + public boolean isAttached(Appender appender) { + return aai.isAttached(appender); + } + + @Override + public void detachAndStopAllAppenders() { + aai.detachAndStopAllAppenders(); + } + + @Override + public boolean detachAppender(Appender appender) { + return aai.detachAppender(appender); + } + + @Override + public boolean detachAppender(String name) { + return aai.detachAppender(name); + } + + private void logOverflowWarning() { + // Create a properly formatted warning event and send directly to child appenders. Used to avoid circular + // dependency between KeyBuffer and BufferingAppender. + Logger logbackLogger = (Logger) org.slf4j.LoggerFactory + .getLogger(BufferingAppender.class); + LoggingEvent warningEvent = new LoggingEvent( + BufferingAppender.class.getName(), logbackLogger, Level.WARN, + "Some logs are not displayed because they were evicted from the buffer. Increase buffer size to store more logs in the buffer.", + null, null); + warningEvent.setTimeStamp(System.currentTimeMillis()); + aai.appendLoopOnAppenders(warningEvent); + } +} diff --git a/powertools-logging/powertools-logging-logback/src/main/java/software/amazon/lambda/powertools/logging/logback/internal/LogbackLoggingManager.java b/powertools-logging/powertools-logging-logback/src/main/java/software/amazon/lambda/powertools/logging/logback/internal/LogbackLoggingManager.java index 86982b444..906ebdad5 100644 --- a/powertools-logging/powertools-logging-logback/src/main/java/software/amazon/lambda/powertools/logging/logback/internal/LogbackLoggingManager.java +++ b/powertools-logging/powertools-logging-logback/src/main/java/software/amazon/lambda/powertools/logging/logback/internal/LogbackLoggingManager.java @@ -14,18 +14,29 @@ package software.amazon.lambda.powertools.logging.logback.internal; -import ch.qos.logback.classic.Level; -import ch.qos.logback.classic.Logger; -import ch.qos.logback.classic.LoggerContext; +import java.util.ArrayList; +import java.util.Collection; +import java.util.Iterator; import java.util.List; +import java.util.stream.Collectors; + import org.slf4j.ILoggerFactory; import org.slf4j.LoggerFactory; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.Appender; +import software.amazon.lambda.powertools.logging.internal.BufferManager; import software.amazon.lambda.powertools.logging.internal.LoggingManager; +import software.amazon.lambda.powertools.logging.logback.BufferingAppender; /** - * LoggingManager for Logback (see {@link LoggingManager}). + * LoggingManager for Logback that provides log level management and buffer operations. + * Implements both {@link LoggingManager} and {@link BufferManager} interfaces. */ -public class LogbackLoggingManager implements LoggingManager { +public class LogbackLoggingManager implements LoggingManager, BufferManager { private final LoggerContext loggerContext; @@ -56,4 +67,34 @@ public void setLogLevel(org.slf4j.event.Level logLevel) { public org.slf4j.event.Level getLogLevel(org.slf4j.Logger logger) { return org.slf4j.event.Level.valueOf(loggerContext.getLogger(logger.getName()).getEffectiveLevel().toString()); } + + /** + * @inheritDoc + */ + @Override + public void flushBuffer() { + getBufferingAppenders().forEach(BufferingAppender::flushBuffer); + } + + /** + * @inheritDoc + */ + @Override + public void clearBuffer() { + getBufferingAppenders().forEach(BufferingAppender::clearBuffer); + } + + private Collection getBufferingAppenders() { + // Search all buffering appenders to avoid relying on the appender name given by the user + return loggerContext.getLoggerList().stream() + .flatMap(logger -> { + Iterator> iterator = logger.iteratorForAppenders(); + List> appenders = new ArrayList<>(); + iterator.forEachRemaining(appenders::add); + return appenders.stream(); + }) + .filter(BufferingAppender.class::isInstance) + .map(BufferingAppender.class::cast) + .collect(Collectors.toList()); + } } diff --git a/powertools-logging/powertools-logging-logback/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-logback/jni-config.json b/powertools-logging/powertools-logging-logback/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-logback/jni-config.json index 753dafdea..c8b081385 100644 --- a/powertools-logging/powertools-logging-logback/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-logback/jni-config.json +++ b/powertools-logging/powertools-logging-logback/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-logback/jni-config.json @@ -3,18 +3,6 @@ "name":"java.lang.Boolean", "methods":[{"name":"getBoolean","parameterTypes":["java.lang.String"] }] }, -{ - "name":"java.lang.String", - "methods":[{"name":"lastIndexOf","parameterTypes":["int"] }, {"name":"substring","parameterTypes":["int"] }] -}, -{ - "name":"java.lang.System", - "methods":[{"name":"getProperty","parameterTypes":["java.lang.String"] }, {"name":"setProperty","parameterTypes":["java.lang.String","java.lang.String"] }] -}, -{ - "name":"org.apache.maven.surefire.booter.ForkedBooter", - "methods":[{"name":"main","parameterTypes":["java.lang.String[]"] }] -}, { "name":"sun.management.VMManagementImpl", "fields":[{"name":"compTimeMonitoringSupport"}, {"name":"currentThreadCpuTimeSupport"}, {"name":"objectMonitorUsageSupport"}, {"name":"otherThreadCpuTimeSupport"}, {"name":"remoteDiagnosticCommandsSupport"}, {"name":"synchronizerUsageSupport"}, {"name":"threadAllocatedMemorySupport"}, {"name":"threadContentionMonitoringSupport"}] diff --git a/powertools-logging/powertools-logging-logback/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-logback/reflect-config.json b/powertools-logging/powertools-logging-logback/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-logback/reflect-config.json index 683933a77..dfc50427f 100644 --- a/powertools-logging/powertools-logging-logback/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-logback/reflect-config.json +++ b/powertools-logging/powertools-logging-logback/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-logback/reflect-config.json @@ -1,4 +1,15 @@ [ +{ + "name":"[Ljava.lang.Object;" +}, +{ + "name":"[Ljava.lang.String;" +}, +{ + "name":"ch.qos.logback.classic.encoder.PatternLayoutEncoder", + "queryAllPublicMethods":true, + "methods":[{"name":"","parameterTypes":[] }] +}, { "name":"ch.qos.logback.classic.joran.SerializedModelConfigurator", "methods":[{"name":"","parameterTypes":[] }] @@ -20,6 +31,18 @@ "name":"ch.qos.logback.core.encoder.Encoder", "methods":[{"name":"valueOf","parameterTypes":["java.lang.String"] }] }, +{ + "name":"ch.qos.logback.core.encoder.LayoutWrappingEncoder", + "methods":[{"name":"setParent","parameterTypes":["ch.qos.logback.core.spi.ContextAware"] }] +}, +{ + "name":"ch.qos.logback.core.pattern.PatternLayoutEncoderBase", + "methods":[{"name":"setPattern","parameterTypes":["java.lang.String"] }] +}, +{ + "name":"ch.qos.logback.core.spi.ContextAware", + "methods":[{"name":"valueOf","parameterTypes":["java.lang.String"] }] +}, { "name":"com.amazonaws.services.lambda.runtime.Context" }, @@ -69,6 +92,10 @@ { "name":"java.lang.Object" }, +{ + "name":"java.lang.ProcessEnvironment", + "fields":[{"name":"theCaseInsensitiveEnvironment"}, {"name":"theEnvironment"}] +}, { "name":"java.lang.String" }, @@ -103,6 +130,10 @@ "queryAllDeclaredMethods":true, "queryAllDeclaredConstructors":true }, +{ + "name":"java.util.Collections$UnmodifiableMap", + "fields":[{"name":"m"}] +}, { "name":"java.util.List", "queryAllDeclaredMethods":true @@ -135,59 +166,9 @@ "fields":[{"name":"IS_COLD_START"}] }, { - "name":"software.amazon.lambda.powertools.logging.LogbackLoggingManagerTest", - "allDeclaredFields":true, - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "queryAllDeclaredConstructors":true, - "methods":[{"name":"","parameterTypes":[] }, {"name":"getLogLevel_shouldReturnConfiguredLogLevel","parameterTypes":[] }, {"name":"resetLogLevel","parameterTypes":[] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.internal.LambdaEcsEncoderTest", - "allDeclaredFields":true, - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "queryAllDeclaredConstructors":true, - "methods":[{"name":"","parameterTypes":[] }, {"name":"cleanUp","parameterTypes":[] }, {"name":"setUp","parameterTypes":[] }, {"name":"shouldLogException","parameterTypes":[] }, {"name":"shouldLogInEcsFormat","parameterTypes":[] }, {"name":"shouldNotLogCloudInfo","parameterTypes":[] }, {"name":"shouldNotLogFunctionInfo","parameterTypes":[] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.internal.LambdaJsonEncoderTest", - "allDeclaredFields":true, - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, + "name":"software.amazon.lambda.powertools.logging.logback.BufferingAppender", "queryAllPublicMethods":true, - "queryAllDeclaredConstructors":true, - "methods":[{"name":"","parameterTypes":[] }, {"name":"cleanUp","parameterTypes":[] }, {"name":"setUp","parameterTypes":[] }, {"name":"shouldLogArgumentsAsJsonWhenUsingKeyValue","parameterTypes":[] }, {"name":"shouldLogArgumentsAsJsonWhenUsingRawJson","parameterTypes":[] }, {"name":"shouldLogEventAsStringForStreamHandler","parameterTypes":[] }, {"name":"shouldLogEventForHandlerWhenEnvVariableSetToTrue","parameterTypes":[] }, {"name":"shouldLogEventForHandlerWithLogEventAnnotation","parameterTypes":[] }, {"name":"shouldLogException","parameterTypes":[] }, {"name":"shouldLogInJsonFormat","parameterTypes":[] }, {"name":"shouldLogResponseForHandlerWhenEnvVariableSetToTrue","parameterTypes":[] }, {"name":"shouldLogResponseForHandlerWithLogResponseAnnotation","parameterTypes":[] }, {"name":"shouldLogResponseForStreamHandler","parameterTypes":[] }, {"name":"shouldLogStructuredArgumentsAsNewEntries","parameterTypes":[] }, {"name":"shouldLogThreadInfo","parameterTypes":[] }, {"name":"shouldLogTimestampDifferently","parameterTypes":[] }, {"name":"shouldNotLogEventForHandlerWhenEnvVariableSetToFalse","parameterTypes":[] }, {"name":"shouldNotLogPowertoolsInfo","parameterTypes":[] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.internal.handler.PowertoolsArguments", - "methods":[{"name":"handleRequest","parameterTypes":["com.amazonaws.services.lambda.runtime.events.SQSEvent$SQSMessage","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.internal.handler.PowertoolsLogEnabled", - "methods":[{"name":"handleRequest","parameterTypes":["java.lang.Object","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.internal.handler.PowertoolsLogEvent", - "methods":[{"name":"handleRequest","parameterTypes":["java.lang.Object","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.internal.handler.PowertoolsLogEventDisabled", - "methods":[{"name":"handleRequest","parameterTypes":["java.lang.Object","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.internal.handler.PowertoolsLogEventForStream", - "methods":[{"name":"handleRequest","parameterTypes":["java.io.InputStream","java.io.OutputStream","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.internal.handler.PowertoolsLogResponse", - "methods":[{"name":"handleRequest","parameterTypes":["java.lang.Object","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.internal.handler.PowertoolsLogResponseForStream", - "methods":[{"name":"handleRequest","parameterTypes":["java.io.InputStream","java.io.OutputStream","com.amazonaws.services.lambda.runtime.Context"] }] + "methods":[{"name":"","parameterTypes":[] }, {"name":"setBufferAtVerbosity","parameterTypes":["java.lang.String"] }, {"name":"setFlushOnErrorLog","parameterTypes":["boolean"] }, {"name":"setMaxBytes","parameterTypes":["int"] }] }, { "name":"software.amazon.lambda.powertools.logging.logback.LambdaEcsEncoder", diff --git a/powertools-logging/powertools-logging-logback/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-logback/resource-config.json b/powertools-logging/powertools-logging-logback/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-logback/resource-config.json index 2fc3c56bd..33d1d61c4 100644 --- a/powertools-logging/powertools-logging-logback/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-logback/resource-config.json +++ b/powertools-logging/powertools-logging-logback/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging-logback/resource-config.json @@ -4,16 +4,12 @@ "pattern":"\\QMETA-INF/services/ch.qos.logback.classic.spi.Configurator\\E" }, { "pattern":"\\QMETA-INF/services/java.lang.System$LoggerFinder\\E" - }, { - "pattern":"\\QMETA-INF/services/java.time.zone.ZoneRulesProvider\\E" }, { "pattern":"\\QMETA-INF/services/javax.xml.parsers.SAXParserFactory\\E" }, { "pattern":"\\QMETA-INF/services/org.slf4j.spi.SLF4JServiceProvider\\E" }, { "pattern":"\\QMETA-INF/services/software.amazon.lambda.powertools.logging.internal.LoggingManager\\E" - }, { - "pattern":"\\Qlogback.scmo\\E" }]}, "bundles":[] } diff --git a/powertools-logging/powertools-logging-logback/src/test/java/software/amazon/lambda/powertools/logging/LogbackLoggingManagerTest.java b/powertools-logging/powertools-logging-logback/src/test/java/software/amazon/lambda/powertools/logging/LogbackLoggingManagerTest.java index 214057917..60f158739 100644 --- a/powertools-logging/powertools-logging-logback/src/test/java/software/amazon/lambda/powertools/logging/LogbackLoggingManagerTest.java +++ b/powertools-logging/powertools-logging-logback/src/test/java/software/amazon/lambda/powertools/logging/LogbackLoggingManagerTest.java @@ -15,15 +15,27 @@ package software.amazon.lambda.powertools.logging; import static org.assertj.core.api.Assertions.assertThat; +import static org.assertj.core.api.Assertions.contentOf; import static org.slf4j.event.Level.DEBUG; import static org.slf4j.event.Level.ERROR; import static org.slf4j.event.Level.WARN; -import org.junit.jupiter.api.Order; +import java.io.File; +import java.io.IOException; +import java.nio.channels.FileChannel; +import java.nio.file.NoSuchFileException; +import java.nio.file.Paths; +import java.nio.file.StandardOpenOption; + +import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import org.slf4j.event.Level; + +import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.joran.JoranConfigurator; +import ch.qos.logback.core.joran.spi.JoranException; import software.amazon.lambda.powertools.logging.logback.internal.LogbackLoggingManager; class LogbackLoggingManagerTest { @@ -31,8 +43,18 @@ class LogbackLoggingManagerTest { private static final Logger LOG = LoggerFactory.getLogger(LogbackLoggingManagerTest.class); private static final Logger ROOT = LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME); + @BeforeEach + void setUp() throws JoranException, IOException { + resetLogbackConfig("/logback-test.xml"); + + 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 - @Order(1) void getLogLevel_shouldReturnConfiguredLogLevel() { LogbackLoggingManager manager = new LogbackLoggingManager(); Level logLevel = manager.getLogLevel(LOG); @@ -43,7 +65,6 @@ void getLogLevel_shouldReturnConfiguredLogLevel() { } @Test - @Order(2) void resetLogLevel() { LogbackLoggingManager manager = new LogbackLoggingManager(); manager.setLogLevel(ERROR); @@ -51,4 +72,35 @@ void resetLogLevel() { Level logLevel = manager.getLogLevel(LOG); assertThat(logLevel).isEqualTo(ERROR); } + + @Test + void shouldDetectMultipleBufferingAppendersRegardlessOfName() throws JoranException { + // Given - configuration with multiple BufferingAppenders with different names + resetLogbackConfig("/logback-multiple-buffering.xml"); + + Logger logger = LoggerFactory.getLogger("test.multiple.appenders"); + + // When - log messages and flush buffers + logger.debug("Test message 1"); + logger.debug("Test message 2"); + + LogbackLoggingManager manager = new LogbackLoggingManager(); + manager.flushBuffer(); + + // Then - both appenders should have flushed their buffers + File logFile = new File("target/logfile.json"); + assertThat(logFile).exists(); + String content = contentOf(logFile); + // Each message should appear twice (once from each BufferingAppender) + assertThat(content.split("Test message 1", -1)).hasSize(3); // 2 occurrences = 3 parts + assertThat(content.split("Test message 2", -1)).hasSize(3); // 2 occurrences = 3 parts + } + + private void resetLogbackConfig(String configFileName) throws JoranException { + LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory(); + context.reset(); + JoranConfigurator configurator = new JoranConfigurator(); + configurator.setContext(context); + configurator.doConfigure(getClass().getResourceAsStream(configFileName)); + } } diff --git a/powertools-logging/powertools-logging-logback/src/test/java/software/amazon/lambda/powertools/logging/logback/BufferingAppenderTest.java b/powertools-logging/powertools-logging-logback/src/test/java/software/amazon/lambda/powertools/logging/logback/BufferingAppenderTest.java new file mode 100644 index 000000000..62d2e3056 --- /dev/null +++ b/powertools-logging/powertools-logging-logback/src/test/java/software/amazon/lambda/powertools/logging/logback/BufferingAppenderTest.java @@ -0,0 +1,150 @@ +package software.amazon.lambda.powertools.logging.logback; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.assertj.core.api.Assertions.contentOf; + +import java.io.File; +import java.io.IOException; +import java.nio.channels.FileChannel; +import java.nio.file.NoSuchFileException; +import java.nio.file.Paths; +import java.nio.file.StandardOpenOption; + +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; +import org.junitpioneer.jupiter.ClearEnvironmentVariable; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.joran.JoranConfigurator; +import ch.qos.logback.core.joran.spi.JoranException; + +class BufferingAppenderTest { + + private Logger logger; + + @BeforeEach + void setUp() throws IOException, JoranException { + try { + FileChannel.open(Paths.get("target/logfile.json"), StandardOpenOption.WRITE).truncate(0).close(); + } catch (NoSuchFileException e) { + // may not be there in the first run + } + + // Configure Logback with BufferingAppender + LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory(); + context.reset(); + + JoranConfigurator configurator = new JoranConfigurator(); + configurator.setContext(context); + configurator.doConfigure(getClass().getResourceAsStream("/logback-buffering-test.xml")); + + logger = LoggerFactory.getLogger(BufferingAppenderTest.class); + } + + @AfterEach + void cleanUp() throws IOException { + try { + FileChannel.open(Paths.get("target/logfile.json"), StandardOpenOption.WRITE).truncate(0).close(); + } catch (NoSuchFileException e) { + // may not be there + } + } + + @Test + void shouldBufferDebugLogsAndFlushOnError() { + // When - log debug messages (should be buffered) + logger.debug("Debug message 1"); + logger.debug("Debug message 2"); + + // Then - no logs written yet + File logFile = new File("target/logfile.json"); + assertThat(contentOf(logFile)).isEmpty(); + + // When - log error (should flush buffer) + logger.error("Error message"); + + // Then - all logs written + assertThat(contentOf(logFile)) + .contains("Debug message 1") + .contains("Debug message 2") + .contains("Error message"); + } + + @Test + @ClearEnvironmentVariable(key = "_X_AMZN_TRACE_ID") + void shouldLogDirectlyWhenNoTraceId() { + // When + logger.debug("Debug without trace"); + + // Then - log written directly + File logFile = new File("target/logfile.json"); + assertThat(contentOf(logFile)).contains("Debug without trace"); + } + + @Test + void shouldNotBufferInfoLogs() { + // When - log info message (above buffer level) + logger.info("Info message"); + + // Then - log written directly + File logFile = new File("target/logfile.json"); + assertThat(contentOf(logFile)).contains("Info message"); + } + + @Test + void shouldFlushBufferManually() { + // When - buffer debug logs + logger.debug("Buffered message"); + File logFile = new File("target/logfile.json"); + assertThat(contentOf(logFile)).isEmpty(); + + // When - manual flush + BufferingAppender appender = getBufferingAppender(); + appender.flushBuffer(); + + // Then - logs written + assertThat(contentOf(logFile)).contains("Buffered message"); + } + + @Test + void shouldClearBufferManually() { + // When - buffer debug logs then clear + logger.debug("Buffered message"); + BufferingAppender appender = getBufferingAppender(); + appender.clearBuffer(); + + // When - log error (should not flush cleared buffer) + logger.error("Error after clear"); + + // Then - only error logged + File logFile = new File("target/logfile.json"); + assertThat(contentOf(logFile)) + .contains("Error after clear") + .doesNotContain("Buffered message"); + } + + @Test + void shouldLogOverflowWarningWhenBufferOverflows() { + // When - fill buffer beyond capacity to trigger overflow + for (int i = 0; i < 100; i++) { + logger.debug("Debug message {}", i); + } + + // When - flush buffer to trigger overflow warning + BufferingAppender appender = getBufferingAppender(); + appender.flushBuffer(); + + // Then - overflow warning should be logged + File logFile = new File("target/logfile.json"); + assertThat(contentOf(logFile)) + .contains("Some logs are not displayed because they were evicted from the buffer"); + } + + private BufferingAppender getBufferingAppender() { + LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory(); + return (BufferingAppender) context.getLogger(BufferingAppenderTest.class).getAppender("TestBufferingAppender"); + } +} diff --git a/powertools-logging/powertools-logging-logback/src/test/resources/logback-buffering-test.xml b/powertools-logging/powertools-logging-logback/src/test/resources/logback-buffering-test.xml new file mode 100644 index 000000000..b9ec3917f --- /dev/null +++ b/powertools-logging/powertools-logging-logback/src/test/resources/logback-buffering-test.xml @@ -0,0 +1,21 @@ + + + + target/logfile.json + + %msg%n + + + + + DEBUG + 1024 + true + + + + + + + diff --git a/powertools-logging/powertools-logging-logback/src/test/resources/logback-multiple-buffering.xml b/powertools-logging/powertools-logging-logback/src/test/resources/logback-multiple-buffering.xml new file mode 100644 index 000000000..84c348d61 --- /dev/null +++ b/powertools-logging/powertools-logging-logback/src/test/resources/logback-multiple-buffering.xml @@ -0,0 +1,28 @@ + + + + target/logfile.json + + %msg%n + + + + + DEBUG + 1024 + true + + + + + DEBUG + 1024 + true + + + + + + + + diff --git a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/Logging.java b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/Logging.java index 9e5e735d1..79d1a95fd 100644 --- a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/Logging.java +++ b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/Logging.java @@ -72,7 +72,7 @@ /** * Set to true if you want to log the response sent by the Lambda function handler.
- * Can also be configured with the 'POWERTOOLS_LOGGER_LOG_RESPONE' environment variable + * Can also be configured with the 'POWERTOOLS_LOGGER_LOG_RESPONSE' environment variable */ boolean logResponse() default false; @@ -102,4 +102,10 @@ * Set this attribute to true if you want all custom keys to be deleted on each request. */ boolean clearState() default false; + + /** + * Set to true if you want to flush the log buffer when an uncaught exception occurs. + * This ensures that buffered logs are output when errors happen. + */ + boolean flushBufferOnUncaughtError() default true; } 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 new file mode 100644 index 000000000..1276c2a87 --- /dev/null +++ b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/PowertoolsLogging.java @@ -0,0 +1,55 @@ +/* + * 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; + +import software.amazon.lambda.powertools.logging.internal.BufferManager; +import software.amazon.lambda.powertools.logging.internal.LoggingManager; +import software.amazon.lambda.powertools.logging.internal.LoggingManagerRegistry; + +/** + * 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. + */ +public final class PowertoolsLogging { + + private PowertoolsLogging() { + // Utility class + } + + /** + * Flushes the log buffer for the current Lambda execution. + * This method will flush any buffered logs to the output stream. + * The operation is backend-independent and works with both Log4j2 and Logback. + */ + public static void flushBuffer() { + LoggingManager loggingManager = LoggingManagerRegistry.getLoggingManager(); + if (loggingManager instanceof BufferManager) { + ((BufferManager) loggingManager).flushBuffer(); + } + } + + /** + * Clears the log buffer for the current Lambda execution. + * This method will discard any buffered logs without outputting them. + * The operation is backend-independent and works with both Log4j2 and Logback. + */ + public static void clearBuffer() { + LoggingManager loggingManager = LoggingManagerRegistry.getLoggingManager(); + if (loggingManager instanceof BufferManager) { + ((BufferManager) loggingManager).clearBuffer(); + } + } +} diff --git a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/BufferManager.java b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/BufferManager.java new file mode 100644 index 000000000..d81d1fd31 --- /dev/null +++ b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/BufferManager.java @@ -0,0 +1,33 @@ +/* + * 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.internal; + +/** + * Interface for logging managers that support buffer operations. + * This extends the logging framework capabilities with buffer-specific functionality. + */ +public interface BufferManager { + /** + * Flushes the log buffer for the current Lambda execution. + * This method will flush any buffered logs to the target appender. + */ + void flushBuffer(); + + /** + * Clears the log buffer for the current Lambda execution. + * This method will discard any buffered logs without outputting them. + */ + void clearBuffer(); +} diff --git a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/DefautlLoggingManager.java b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/DefaultLoggingManager.java similarity index 94% rename from powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/DefautlLoggingManager.java rename to powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/DefaultLoggingManager.java index 5326f53e6..ed2c14c38 100644 --- a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/DefautlLoggingManager.java +++ b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/DefaultLoggingManager.java @@ -21,7 +21,7 @@ * When no LoggingManager is found, setting a default one with no action on logging implementation * Powertools cannot change the log level based on the environment variable, will use the logger configuration */ -public class DefautlLoggingManager implements LoggingManager { +public class DefaultLoggingManager implements LoggingManager { @Override public void setLogLevel(Level logLevel) { diff --git a/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/KeyBuffer.java b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/KeyBuffer.java new file mode 100644 index 000000000..3510a544d --- /dev/null +++ b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/KeyBuffer.java @@ -0,0 +1,95 @@ +/* + * 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.internal; + +import java.util.ArrayDeque; +import java.util.Deque; +import java.util.Map; +import java.util.concurrent.ConcurrentHashMap; +import java.util.function.Function; + +/** + * Thread-safe buffer that stores events by key with size-based eviction. + * + *

Maintains separate queues per key. When buffer size exceeds maxBytes, + * oldest events are evicted FIFO. Events larger than maxBytes are rejected. + * + * @param key type for buffering + * @param event type to buffer + */ +public class KeyBuffer { + + private final Map> keyBufferCache = new ConcurrentHashMap<>(); + private final Map overflowTriggered = new ConcurrentHashMap<>(); + private final int maxBytes; + private final Function sizeCalculator; + private final Runnable overflowWarningLogger; + + @SuppressWarnings("java:S106") // Using System.err to avoid circular dependency with logging implementation + public KeyBuffer(int maxBytes, Function sizeCalculator) { + this(maxBytes, sizeCalculator, () -> System.err.println("WARN [" + KeyBuffer.class.getSimpleName() + + "] - Some logs are not displayed because they were evicted from the buffer. Increase buffer size to store more logs in the buffer.")); + } + + public KeyBuffer(int maxBytes, Function sizeCalculator, Runnable overflowWarningLogger) { + this.maxBytes = maxBytes; + this.sizeCalculator = sizeCalculator; + this.overflowWarningLogger = overflowWarningLogger; + } + + public void add(K key, T event) { + int eventSize = sizeCalculator.apply(event); + // Immediately reject events larger than the whole buffer-size to avoid evicting all elements. + if (eventSize > maxBytes) { + overflowTriggered.put(key, true); + return; + } + + Deque buffer = keyBufferCache.computeIfAbsent(key, k -> new ArrayDeque<>()); + synchronized (buffer) { + buffer.add(event); + while (getBufferSize(buffer) > maxBytes && !buffer.isEmpty()) { + overflowTriggered.put(key, true); + buffer.removeFirst(); + } + } + } + + public Deque removeAll(K key) { + logOverflowWarningIfNeeded(key); + Deque buffer = keyBufferCache.remove(key); + if (buffer != null) { + synchronized (buffer) { + return new ArrayDeque<>(buffer); + } + } + return buffer; + } + + public void clear(K key) { + keyBufferCache.remove(key); + overflowTriggered.remove(key); + } + + private void logOverflowWarningIfNeeded(K key) { + if (Boolean.TRUE.equals(overflowTriggered.remove(key))) { + overflowWarningLogger.run(); + } + } + + private int getBufferSize(Deque buffer) { + return buffer.stream().mapToInt(sizeCalculator::apply).sum(); + } +} 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 eccfdae4f..591283996 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 @@ -35,9 +35,6 @@ import static software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields.FUNCTION_TRACE_ID; import static software.amazon.lambda.powertools.logging.internal.PowertoolsLoggedFields.SERVICE; -import com.amazonaws.services.lambda.runtime.Context; -import com.fasterxml.jackson.databind.JsonNode; -import io.burt.jmespath.Expression; import java.io.ByteArrayInputStream; import java.io.ByteArrayOutputStream; import java.io.IOException; @@ -45,14 +42,10 @@ import java.io.InputStreamReader; import java.io.OutputStream; import java.io.OutputStreamWriter; -import java.io.PrintStream; -import java.security.AccessController; -import java.security.PrivilegedAction; -import java.util.ArrayList; import java.util.Arrays; -import java.util.List; +import java.util.Locale; import java.util.Random; -import java.util.ServiceLoader; + import org.aspectj.lang.ProceedingJoinPoint; import org.aspectj.lang.annotation.Around; import org.aspectj.lang.annotation.Aspect; @@ -63,10 +56,14 @@ 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.utilities.JsonConfig; - @Aspect @DeclarePrecedence("*, software.amazon.lambda.powertools.logging.internal.LambdaLoggingAspect") public final class LambdaLoggingAspect { @@ -77,7 +74,7 @@ public final class LambdaLoggingAspect { private static final LoggingManager LOGGING_MANAGER; static { - LOGGING_MANAGER = getLoggingManagerFromServiceLoader(); + LOGGING_MANAGER = LoggingManagerRegistry.getLoggingManager(); setLogLevel(); @@ -90,7 +87,8 @@ static void setLogLevel() { 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.", + 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); } } @@ -102,7 +100,7 @@ static void setLogLevel() { private static Level getLevelFromString(String level) { if (Arrays.stream(Level.values()).anyMatch(slf4jLevel -> slf4jLevel.name().equalsIgnoreCase(level))) { - return Level.valueOf(level.toUpperCase()); + return Level.valueOf(level.toUpperCase(Locale.ROOT)); } else { // FATAL does not exist in slf4j if ("FATAL".equalsIgnoreCase(level)) { @@ -113,60 +111,14 @@ private static Level getLevelFromString(String level) { return Level.INFO; } - /** - * Use {@link ServiceLoader} to lookup for a {@link LoggingManager}. - * A file software.amazon.lambda.powertools.logging.internal.LoggingManager must be created in - * META-INF/services/ folder with the appropriate implementation of the {@link LoggingManager} - * - * @return an instance of {@link LoggingManager} - * @throws IllegalStateException if no {@link LoggingManager} could be found - */ - @SuppressWarnings("java:S106") // S106: System.err is used rather than logger to make sure message is printed - private static LoggingManager getLoggingManagerFromServiceLoader() { - ServiceLoader loggingManagers; - SecurityManager securityManager = System.getSecurityManager(); - if (securityManager == null) { - loggingManagers = ServiceLoader.load(LoggingManager.class); - } else { - final PrivilegedAction> action = () -> ServiceLoader.load(LoggingManager.class); - loggingManagers = AccessController.doPrivileged(action); - } - - List loggingManagerList = new ArrayList<>(); - for (LoggingManager lm : loggingManagers) { - loggingManagerList.add(lm); - } - return getLoggingManager(loggingManagerList, System.err); - } - - static LoggingManager getLoggingManager(List loggingManagerList, PrintStream printStream) { - LoggingManager loggingManager; - if (loggingManagerList.isEmpty()) { - printStream.println("ERROR. No LoggingManager was found on the classpath"); - printStream.println("ERROR. Applying default LoggingManager: POWERTOOLS_LOG_LEVEL variable is ignored"); - printStream.println("ERROR. Make sure to add either powertools-logging-log4j or powertools-logging-logback to your dependencies"); - loggingManager = new DefautlLoggingManager(); - } else { - if (loggingManagerList.size() > 1) { - printStream.println("WARN. Multiple LoggingManagers were found on the classpath"); - for (LoggingManager manager : loggingManagerList) { - printStream.println("WARN. Found LoggingManager: [" + manager + "]"); - } - printStream.println("WARN. Make sure to have only one of powertools-logging-log4j OR powertools-logging-logback to your dependencies"); - printStream.println("WARN. Using the first LoggingManager found on the classpath: [" + loggingManagerList.get(0) + "]"); - } - loggingManager = loggingManagerList.get(0); - } - return loggingManager; - } - private static void setLogLevels(Level logLevel) { LOGGING_MANAGER.setLogLevel(logLevel); } - @SuppressWarnings({"EmptyMethod"}) + @SuppressWarnings({ "EmptyMethod" }) @Pointcut("@annotation(logging)") public void callAt(Logging logging) { + // Pointcut method - body intentionally empty } /** @@ -174,69 +126,51 @@ public void callAt(Logging logging) { */ @Around(value = "callAt(logging) && execution(@Logging * *.*(..))", argNames = "pjp,logging") public Object around(ProceedingJoinPoint pjp, - Logging logging) throws Throwable { + Logging logging) throws Throwable { boolean isOnRequestHandler = placedOnRequestHandler(pjp); boolean isOnRequestStreamHandler = placedOnStreamHandler(pjp); setLogLevelBasedOnSamplingRate(pjp, logging); - addLambdaContextToLoggingContext(pjp); - getXrayTraceId().ifPresent(xRayTraceId -> MDC.put(FUNCTION_TRACE_ID.getName(), xRayTraceId)); - // Log Event Object[] proceedArgs = logEvent(pjp, logging, isOnRequestHandler, isOnRequestStreamHandler); if (!logging.correlationIdPath().isEmpty()) { - captureCorrelationId(logging.correlationIdPath(), proceedArgs, isOnRequestHandler, isOnRequestStreamHandler); + captureCorrelationId(logging.correlationIdPath(), proceedArgs, isOnRequestHandler, + isOnRequestStreamHandler); } - // To log the result of a RequestStreamHandler (OutputStream), we need to do the following: - // 1. backup a reference to the OutputStream provided by Lambda - // 2. create a temporary OutputStream and pass it to the handler method - // 3. retrieve this temporary stream to log it (if enabled) - // 4. write it back to the OutputStream provided by Lambda + @SuppressWarnings("PMD.CloseResource") // Lambda-owned stream, not ours to close OutputStream backupOutputStream = null; - if ((logging.logResponse() || POWERTOOLS_LOG_RESPONSE) && isOnRequestStreamHandler) { - backupOutputStream = (OutputStream) proceedArgs[1]; - proceedArgs[1] = new ByteArrayOutputStream(); + if (isOnRequestStreamHandler) { + // To log the result of a RequestStreamHandler (OutputStream), we need to do the following: + // 1. backup a reference to the OutputStream provided by Lambda + // 2. create a temporary OutputStream and pass it to the handler method + // 3. retrieve this temporary stream to log it (if enabled) + // 4. write it back to the OutputStream provided by Lambda + backupOutputStream = prepareOutputStreamForLogging(logging, proceedArgs); } Object lambdaFunctionResponse; - try { - // Call Function Handler lambdaFunctionResponse = pjp.proceed(proceedArgs); - } catch (Throwable t) { - if (logging.logError() || POWERTOOLS_LOG_ERROR) { - // logging the exception with additional context - logger(pjp).error(MarkerFactory.getMarker("FATAL"), "Exception in Lambda Handler", t); - } + } catch (Throwable t) { // NOPMD - AspectJ proceed() throws Throwable + handleException(pjp, logging, t); throw t; } finally { - if (logging.clearState()) { - MDC.clear(); - } - coldStartDone(); + performCleanup(logging); } - // Log Response - if ((logging.logResponse() || POWERTOOLS_LOG_RESPONSE)) { - if (isOnRequestHandler) { - logRequestHandlerResponse(pjp, lambdaFunctionResponse); - } else if (isOnRequestStreamHandler && backupOutputStream != null) { - byte[] bytes = ((ByteArrayOutputStream)proceedArgs[1]).toByteArray(); - logRequestStreamHandlerResponse(pjp, bytes); - backupOutputStream.write(bytes); - } - } + logResponse(pjp, logging, lambdaFunctionResponse, isOnRequestHandler, isOnRequestStreamHandler, + backupOutputStream, proceedArgs); return lambdaFunctionResponse; } private Object[] logEvent(ProceedingJoinPoint pjp, Logging logging, - boolean isOnRequestHandler, boolean isOnRequestStreamHandler) { + boolean isOnRequestHandler, boolean isOnRequestStreamHandler) { Object[] proceedArgs = pjp.getArgs(); if (logging.logEvent() || POWERTOOLS_LOG_EVENT) { @@ -260,7 +194,7 @@ private void addLambdaContextToLoggingContext(ProceedingJoinPoint pjp) { } private void setLogLevelBasedOnSamplingRate(final ProceedingJoinPoint pjp, - final Logging logging) { + final Logging logging) { double samplingRate = samplingRate(logging); if (isHandlerMethod(pjp)) { @@ -346,9 +280,9 @@ private void logRequestStreamHandlerResponse(final ProceedingJoinPoint pjp, fina } private void captureCorrelationId(final String correlationIdPath, - Object[] proceedArgs, - final boolean isOnRequestHandler, - final boolean isOnRequestStreamHandler) { + Object[] proceedArgs, + final boolean isOnRequestHandler, + final boolean isOnRequestStreamHandler) { if (isOnRequestHandler) { JsonNode jsonNode = JsonConfig.get().getObjectMapper().valueToTree(proceedArgs[0]); setCorrelationIdFromNode(correlationIdPath, jsonNode); @@ -377,11 +311,10 @@ private void setCorrelationIdFromNode(String correlationIdPath, JsonNode jsonNod } } - private byte[] bytesFromInputStreamSafely(final InputStream inputStream) throws IOException { try (ByteArrayOutputStream out = new ByteArrayOutputStream(); - InputStreamReader reader = new InputStreamReader(inputStream, UTF_8)) { - OutputStreamWriter writer = new OutputStreamWriter(out, UTF_8); + InputStreamReader reader = new InputStreamReader(inputStream, UTF_8); + OutputStreamWriter writer = new OutputStreamWriter(out, UTF_8)) { int n; char[] buffer = new char[4096]; while (-1 != (n = reader.read(buffer))) { @@ -392,6 +325,53 @@ private byte[] bytesFromInputStreamSafely(final InputStream inputStream) throws } } + private OutputStream prepareOutputStreamForLogging(Logging logging, + Object[] proceedArgs) { + if (logging.logResponse() || POWERTOOLS_LOG_RESPONSE) { + OutputStream backupOutputStream = (OutputStream) proceedArgs[1]; + proceedArgs[1] = new ByteArrayOutputStream(); + return backupOutputStream; + } + return null; + } + + private void handleException(ProceedingJoinPoint pjp, Logging logging, Throwable t) { + if (LOGGING_MANAGER instanceof BufferManager) { + if (logging.flushBufferOnUncaughtError()) { + ((BufferManager) LOGGING_MANAGER).flushBuffer(); + } else { + ((BufferManager) LOGGING_MANAGER).clearBuffer(); + } + } + if (logging.logError() || POWERTOOLS_LOG_ERROR) { + logger(pjp).error(MarkerFactory.getMarker("FATAL"), "Exception in Lambda Handler", t); + } + } + + 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 { + if (logging.logResponse() || POWERTOOLS_LOG_RESPONSE) { + if (isOnRequestHandler) { + logRequestHandlerResponse(pjp, lambdaFunctionResponse); + } else if (isOnRequestStreamHandler && backupOutputStream != null) { + byte[] bytes = ((ByteArrayOutputStream) proceedArgs[1]).toByteArray(); + logRequestStreamHandlerResponse(pjp, bytes); + backupOutputStream.write(bytes); + } + } + } + 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/LoggingManagerRegistry.java b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LoggingManagerRegistry.java new file mode 100644 index 000000000..463981903 --- /dev/null +++ b/powertools-logging/src/main/java/software/amazon/lambda/powertools/logging/internal/LoggingManagerRegistry.java @@ -0,0 +1,99 @@ +/* + * 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.internal; + +import java.io.PrintStream; +import java.security.AccessController; +import java.security.PrivilegedAction; +import java.util.ArrayList; +import java.util.List; +import java.util.ServiceLoader; + +/** + * Thread-safe singleton registry for LoggingManager instances. + * Handles lazy loading and caching of the LoggingManager implementation. + */ +public final class LoggingManagerRegistry { + + // Used with double-checked locking within getLoggingManger() + @SuppressWarnings({ "java:S3077", "PMD.AvoidUsingVolatile" }) + private static volatile LoggingManager instance; + + private LoggingManagerRegistry() { + // Utility class + } + + /** + * Gets the LoggingManager instance, loading it lazily on first access. + * + * @return the LoggingManager instance + */ + public static LoggingManager getLoggingManager() { + LoggingManager manager = instance; + if (manager == null) { + synchronized (LoggingManagerRegistry.class) { + manager = instance; + if (manager == null) { + manager = loadLoggingManager(); + instance = manager; + } + } + } + return manager; + } + + @SuppressWarnings("java:S106") // S106: System.err is used rather than logger to make sure message is printed + private static LoggingManager loadLoggingManager() { + ServiceLoader loggingManagers; + SecurityManager securityManager = System.getSecurityManager(); + if (securityManager == null) { + loggingManagers = ServiceLoader.load(LoggingManager.class); + } else { + final PrivilegedAction> action = () -> ServiceLoader + .load(LoggingManager.class); + loggingManagers = AccessController.doPrivileged(action); + } + + List loggingManagerList = new ArrayList<>(); + for (LoggingManager lm : loggingManagers) { + loggingManagerList.add(lm); + } + return selectLoggingManager(loggingManagerList, System.err); + } + + static LoggingManager selectLoggingManager(List loggingManagerList, PrintStream printStream) { + LoggingManager loggingManager; + if (loggingManagerList.isEmpty()) { + printStream.println("ERROR. No LoggingManager was found on the classpath"); + printStream.println("ERROR. Applying default LoggingManager: POWERTOOLS_LOG_LEVEL variable is ignored"); + printStream.println( + "ERROR. Make sure to add either powertools-logging-log4j or powertools-logging-logback to your dependencies"); + loggingManager = new DefaultLoggingManager(); + } else { + if (loggingManagerList.size() > 1) { + printStream.println("WARN. Multiple LoggingManagers were found on the classpath"); + for (LoggingManager manager : loggingManagerList) { + printStream.println("WARN. Found LoggingManager: [" + manager + "]"); + } + printStream.println( + "WARN. Make sure to have only one of powertools-logging-log4j OR powertools-logging-logback in your dependencies"); + printStream.println("WARN. Using the first LoggingManager found on the classpath: [" + + loggingManagerList.get(0) + "]"); + } + loggingManager = loggingManagerList.get(0); + } + return loggingManager; + } +} diff --git a/powertools-logging/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging/jni-config.json b/powertools-logging/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging/jni-config.json index 2c4de0562..c8b081385 100644 --- a/powertools-logging/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging/jni-config.json +++ b/powertools-logging/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging/jni-config.json @@ -3,22 +3,6 @@ "name":"java.lang.Boolean", "methods":[{"name":"getBoolean","parameterTypes":["java.lang.String"] }] }, -{ - "name":"java.lang.String", - "methods":[{"name":"lastIndexOf","parameterTypes":["int"] }, {"name":"substring","parameterTypes":["int"] }] -}, -{ - "name":"java.lang.System", - "methods":[{"name":"getProperty","parameterTypes":["java.lang.String"] }, {"name":"setProperty","parameterTypes":["java.lang.String","java.lang.String"] }] -}, -{ - "name":"org.apache.maven.surefire.booter.ForkedBooter", - "methods":[{"name":"main","parameterTypes":["java.lang.String[]"] }] -}, -{ - "name":"sun.instrument.InstrumentationImpl", - "methods":[{"name":"","parameterTypes":["long","boolean","boolean","boolean"] }, {"name":"loadClassAndCallAgentmain","parameterTypes":["java.lang.String","java.lang.String"] }, {"name":"loadClassAndCallPremain","parameterTypes":["java.lang.String","java.lang.String"] }, {"name":"transform","parameterTypes":["java.lang.Module","java.lang.ClassLoader","java.lang.String","java.lang.Class","java.security.ProtectionDomain","byte[]","boolean"] }] -}, { "name":"sun.management.VMManagementImpl", "fields":[{"name":"compTimeMonitoringSupport"}, {"name":"currentThreadCpuTimeSupport"}, {"name":"objectMonitorUsageSupport"}, {"name":"otherThreadCpuTimeSupport"}, {"name":"remoteDiagnosticCommandsSupport"}, {"name":"synchronizerUsageSupport"}, {"name":"threadAllocatedMemorySupport"}, {"name":"threadContentionMonitoringSupport"}] diff --git a/powertools-logging/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging/reflect-config.json b/powertools-logging/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging/reflect-config.json index 7347b8400..4c66ebd97 100644 --- a/powertools-logging/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging/reflect-config.json +++ b/powertools-logging/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging/reflect-config.json @@ -23,21 +23,7 @@ "methods":[{"name":"","parameterTypes":[] }] }, { - "name":"com.amazonaws.services.lambda.runtime.Context", - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "queryAllDeclaredConstructors":true, - "methods":[{"name":"getAwsRequestId","parameterTypes":[] }, {"name":"getClientContext","parameterTypes":[] }, {"name":"getFunctionName","parameterTypes":[] }, {"name":"getFunctionVersion","parameterTypes":[] }, {"name":"getIdentity","parameterTypes":[] }, {"name":"getInvokedFunctionArn","parameterTypes":[] }, {"name":"getLogGroupName","parameterTypes":[] }, {"name":"getLogStreamName","parameterTypes":[] }, {"name":"getLogger","parameterTypes":[] }, {"name":"getMemoryLimitInMB","parameterTypes":[] }, {"name":"getRemainingTimeInMillis","parameterTypes":[] }] -}, -{ - "name":"com.amazonaws.services.lambda.runtime.RequestHandler", - "allDeclaredClasses":true, - "queryAllPublicMethods":true -}, -{ - "name":"com.amazonaws.services.lambda.runtime.RequestStreamHandler", - "allDeclaredClasses":true, - "queryAllPublicMethods":true + "name":"com.amazonaws.services.lambda.runtime.Context" }, { "name":"com.amazonaws.services.lambda.runtime.events.APIGatewayProxyRequestEvent", @@ -129,6 +115,7 @@ "name":"com.amazonaws.services.lambda.runtime.tests.EventArgumentsProvider", "queryAllDeclaredMethods":true, "queryAllPublicMethods":true, + "queryAllDeclaredConstructors":true, "methods":[{"name":"","parameterTypes":[] }] }, { @@ -139,9 +126,6 @@ "name":"com.fasterxml.jackson.databind.ext.Java7SupportImpl", "methods":[{"name":"","parameterTypes":[] }] }, -{ - "name":"com.sun.tools.attach.VirtualMachine" -}, { "name":"double", "queryAllDeclaredMethods":true @@ -159,137 +143,43 @@ "name":"java.io.Serializable", "allDeclaredClasses":true, "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "queryAllDeclaredConstructors":true + "queryAllPublicMethods":true }, { "name":"java.lang.Boolean" }, -{ - "name":"java.lang.Class", - "methods":[{"name":"forName","parameterTypes":["java.lang.String"] }, {"name":"getAnnotatedInterfaces","parameterTypes":[] }, {"name":"getAnnotatedSuperclass","parameterTypes":[] }, {"name":"getDeclaredMethod","parameterTypes":["java.lang.String","java.lang.Class[]"] }, {"name":"getMethod","parameterTypes":["java.lang.String","java.lang.Class[]"] }, {"name":"getModule","parameterTypes":[] }, {"name":"getNestHost","parameterTypes":[] }, {"name":"getNestMembers","parameterTypes":[] }, {"name":"getPermittedSubclasses","parameterTypes":[] }, {"name":"getRecordComponents","parameterTypes":[] }, {"name":"isNestmateOf","parameterTypes":["java.lang.Class"] }, {"name":"isRecord","parameterTypes":[] }, {"name":"isSealed","parameterTypes":[] }] -}, -{ - "name":"java.lang.ClassLoader", - "methods":[{"name":"getDefinedPackage","parameterTypes":["java.lang.String"] }, {"name":"getUnnamedModule","parameterTypes":[] }, {"name":"registerAsParallelCapable","parameterTypes":[] }] -}, { "name":"java.lang.Cloneable", "queryAllDeclaredMethods":true }, { - "name":"java.lang.Comparable", - "allDeclaredClasses":true, - "queryAllPublicMethods":true -}, -{ - "name":"java.lang.Enum", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"java.lang.Module", - "methods":[{"name":"addExports","parameterTypes":["java.lang.String","java.lang.Module"] }, {"name":"addReads","parameterTypes":["java.lang.Module"] }, {"name":"canRead","parameterTypes":["java.lang.Module"] }, {"name":"getClassLoader","parameterTypes":[] }, {"name":"getName","parameterTypes":[] }, {"name":"getPackages","parameterTypes":[] }, {"name":"getResourceAsStream","parameterTypes":["java.lang.String"] }, {"name":"isExported","parameterTypes":["java.lang.String"] }, {"name":"isExported","parameterTypes":["java.lang.String","java.lang.Module"] }, {"name":"isNamed","parameterTypes":[] }, {"name":"isOpen","parameterTypes":["java.lang.String","java.lang.Module"] }] -}, -{ - "name":"java.lang.Object", - "queryAllDeclaredMethods":true, - "queryAllDeclaredConstructors":true, - "methods":[{"name":"","parameterTypes":[] }, {"name":"clone","parameterTypes":[] }, {"name":"getClass","parameterTypes":[] }, {"name":"toString","parameterTypes":[] }] + "name":"java.lang.Object" }, { "name":"java.lang.ProcessEnvironment", "fields":[{"name":"theCaseInsensitiveEnvironment"}, {"name":"theEnvironment"}] }, { - "name":"java.lang.ProcessHandle", - "methods":[{"name":"current","parameterTypes":[] }, {"name":"pid","parameterTypes":[] }] -}, -{ - "name":"java.lang.Runtime", - "methods":[{"name":"version","parameterTypes":[] }] + "name":"java.lang.String" }, { - "name":"java.lang.Runtime$Version", - "methods":[{"name":"feature","parameterTypes":[] }] -}, -{ - "name":"java.lang.StackWalker" -}, -{ - "name":"java.lang.System", - "methods":[{"name":"getSecurityManager","parameterTypes":[] }] -}, -{ - "name":"java.lang.annotation.Retention", - "queryAllDeclaredMethods":true, - "queryAllDeclaredConstructors":true + "name":"java.util.AbstractMap", + "allDeclaredFields":true, + "queryAllDeclaredMethods":true }, { - "name":"java.lang.annotation.Target", + "name":"java.util.Collections$SingletonMap", + "allDeclaredFields":true, "queryAllDeclaredMethods":true, "queryAllDeclaredConstructors":true }, -{ - "name":"java.lang.constant.Constable", - "allDeclaredClasses":true, - "queryAllPublicMethods":true -}, -{ - "name":"java.lang.invoke.MethodHandle", - "methods":[{"name":"bindTo","parameterTypes":["java.lang.Object"] }, {"name":"invokeWithArguments","parameterTypes":["java.lang.Object[]"] }] -}, -{ - "name":"java.lang.invoke.MethodHandles", - "methods":[{"name":"lookup","parameterTypes":[] }] -}, -{ - "name":"java.lang.invoke.MethodHandles$Lookup", - "methods":[{"name":"findVirtual","parameterTypes":["java.lang.Class","java.lang.String","java.lang.invoke.MethodType"] }] -}, -{ - "name":"java.lang.invoke.MethodType", - "methods":[{"name":"methodType","parameterTypes":["java.lang.Class","java.lang.Class[]"] }] -}, -{ - "name":"java.lang.reflect.AccessibleObject", - "methods":[{"name":"setAccessible","parameterTypes":["boolean"] }] -}, -{ - "name":"java.lang.reflect.AnnotatedArrayType", - "methods":[{"name":"getAnnotatedGenericComponentType","parameterTypes":[] }] -}, -{ - "name":"java.lang.reflect.AnnotatedType", - "methods":[{"name":"getType","parameterTypes":[] }] -}, -{ - "name":"java.lang.reflect.Executable", - "methods":[{"name":"getAnnotatedExceptionTypes","parameterTypes":[] }, {"name":"getAnnotatedParameterTypes","parameterTypes":[] }, {"name":"getAnnotatedReceiverType","parameterTypes":[] }, {"name":"getParameterCount","parameterTypes":[] }, {"name":"getParameters","parameterTypes":[] }] -}, -{ - "name":"java.lang.reflect.Method", - "methods":[{"name":"getAnnotatedReturnType","parameterTypes":[] }] -}, -{ - "name":"java.lang.reflect.Parameter", - "methods":[{"name":"getModifiers","parameterTypes":[] }, {"name":"getName","parameterTypes":[] }, {"name":"isNamePresent","parameterTypes":[] }] -}, -{ - "name":"java.security.AccessController", - "methods":[{"name":"doPrivileged","parameterTypes":["java.security.PrivilegedAction"] }, {"name":"doPrivileged","parameterTypes":["java.security.PrivilegedExceptionAction"] }] -}, { "name":"java.util.Collections$UnmodifiableMap", "fields":[{"name":"m"}] }, { - "name":"java.util.Map" -}, -{ - "name":"java.util.concurrent.ForkJoinTask", - "fields":[{"name":"aux"}, {"name":"status"}] + "name":"java.util.Map", + "queryAllDeclaredMethods":true }, { "name":"java.util.concurrent.atomic.AtomicBoolean", @@ -303,22 +193,10 @@ "name":"java.util.function.Consumer", "queryAllPublicMethods":true }, -{ - "name":"jdk.internal.misc.Unsafe" -}, -{ - "name":"kotlin.jvm.JvmInline" -}, { "name":"org.apiguardian.api.API", "queryAllPublicMethods":true }, -{ - "name":"org.aspectj.runtime.internal.AroundClosure", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, { "name":"org.joda.time.DateTime" }, @@ -349,42 +227,6 @@ "allDeclaredClasses":true, "queryAllPublicMethods":true }, -{ - "name":"org.slf4j.test.OutputChoice", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"org.slf4j.test.OutputChoice$OutputChoiceType", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"org.slf4j.test.TestLogger", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"org.slf4j.test.TestLoggerConfiguration", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"org.slf4j.test.TestLoggerFactory", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"org.slf4j.test.TestServiceProvider", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, { "name":"software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor", "fields":[{"name":"IS_COLD_START"}, {"name":"SERVICE_NAME"}] @@ -396,232 +238,11 @@ "queryAllDeclaredMethods":true, "queryAllPublicMethods":true, "queryAllDeclaredConstructors":true, - "methods":[{"name":"","parameterTypes":[] }, {"name":"arrayArgument","parameterTypes":[] }, {"name":"jsonArgument","parameterTypes":[] }, {"name":"keyValueArgument","parameterTypes":[] }, {"name":"mapArgument","parameterTypes":[] }, {"name":"setUp","parameterTypes":[] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogAlbCorrelationId", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"handleRequest","parameterTypes":["com.amazonaws.services.lambda.runtime.events.ApplicationLoadBalancerRequestEvent","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogAlbCorrelationId$AjcClosure1", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogApiGatewayHttpApiCorrelationId", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"handleRequest","parameterTypes":["com.amazonaws.services.lambda.runtime.events.APIGatewayV2HTTPEvent","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogApiGatewayHttpApiCorrelationId$AjcClosure1", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogApiGatewayRestApiCorrelationId", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"handleRequest","parameterTypes":["com.amazonaws.services.lambda.runtime.events.APIGatewayProxyRequestEvent","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogApiGatewayRestApiCorrelationId$AjcClosure1", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogAppSyncCorrelationId", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"handleRequest","parameterTypes":["java.io.InputStream","java.io.OutputStream","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogAppSyncCorrelationId$AjcClosure1", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogClearState", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"handleRequest","parameterTypes":["java.util.Map","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogClearState$AjcClosure1", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogDisabled", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogDisabledForStream", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEnabled", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"anotherMethod","parameterTypes":[] }, {"name":"handleRequest","parameterTypes":["java.lang.Object","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEnabled$AjcClosure1", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEnabled$AjcClosure3", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEnabledForStream", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"handleRequest","parameterTypes":["java.io.InputStream","java.io.OutputStream","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEnabledForStream$AjcClosure1", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogError", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"handleRequest","parameterTypes":["java.lang.Object","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogError$AjcClosure1", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEvent", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"handleRequest","parameterTypes":["java.lang.Object","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEvent$AjcClosure1", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEventBridgeCorrelationId", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"handleRequest","parameterTypes":["java.io.InputStream","java.io.OutputStream","com.amazonaws.services.lambda.runtime.Context"] }] + "methods":[{"name":"","parameterTypes":[] }, {"name":"arrayArgument","parameterTypes":[] }, {"name":"emptyMapArgument","parameterTypes":[] }, {"name":"jsonArgument","parameterTypes":[] }, {"name":"keyValueArgument","parameterTypes":[] }, {"name":"mapArgument","parameterTypes":[] }, {"name":"reservedKeywordArgumentIgnored","parameterTypes":[] }, {"name":"setUp","parameterTypes":[] }] }, { - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEventBridgeCorrelationId$AjcClosure1", + "name":"software.amazon.lambda.powertools.logging.internal.BufferManager", "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEventEnvVar", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"handleRequest","parameterTypes":["java.lang.Object","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEventEnvVar$AjcClosure1", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEventForStream", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"handleRequest","parameterTypes":["java.io.InputStream","java.io.OutputStream","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEventForStream$AjcClosure1", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogResponse", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"handleRequest","parameterTypes":["java.lang.Object","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogResponse$AjcClosure1", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogResponseForStream", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"handleRequest","parameterTypes":["java.io.InputStream","java.io.OutputStream","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogResponseForStream$AjcClosure1", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogSamplingDisabled", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"handleRequest","parameterTypes":["java.lang.Object","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogSamplingDisabled$AjcClosure1", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogSamplingEnabled", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, - "methods":[{"name":"handleRequest","parameterTypes":["java.lang.Object","com.amazonaws.services.lambda.runtime.Context"] }] -}, -{ - "name":"software.amazon.lambda.powertools.logging.handlers.PowertoolsLogSamplingEnabled$AjcClosure1", - "allDeclaredClasses":true, - "queryAllDeclaredMethods":true, "queryAllPublicMethods":true }, { @@ -647,23 +268,15 @@ { "name":"software.amazon.lambda.powertools.logging.model.Basket", "allDeclaredFields":true, - "allDeclaredClasses":true, "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, "queryAllDeclaredConstructors":true, "methods":[{"name":"getProducts","parameterTypes":[] }] }, { "name":"software.amazon.lambda.powertools.logging.model.Product", "allDeclaredFields":true, - "allDeclaredClasses":true, "queryAllDeclaredMethods":true, - "queryAllPublicMethods":true, "queryAllDeclaredConstructors":true, "methods":[{"name":"getId","parameterTypes":[] }, {"name":"getName","parameterTypes":[] }, {"name":"getPrice","parameterTypes":[] }] -}, -{ - "name":"sun.reflect.ReflectionFactory", - "methods":[{"name":"getReflectionFactory","parameterTypes":[] }, {"name":"newConstructorForSerialization","parameterTypes":["java.lang.Class","java.lang.reflect.Constructor"] }] } ] diff --git a/powertools-logging/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging/resource-config.json b/powertools-logging/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging/resource-config.json index ca77675e0..832be3d72 100644 --- a/powertools-logging/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging/resource-config.json +++ b/powertools-logging/src/main/resources/META-INF/native-image/software.amazon.lambda/powertools-logging/resource-config.json @@ -2,8 +2,6 @@ "resources":{ "includes":[{ "pattern":"\\QMETA-INF/services/java.lang.System$LoggerFinder\\E" - }, { - "pattern":"\\QMETA-INF/services/java.time.zone.ZoneRulesProvider\\E" }, { "pattern":"\\QMETA-INF/services/org.apache.maven.surefire.spi.MasterProcessChannelProcessorFactory\\E" }, { @@ -14,10 +12,6 @@ "pattern":"\\QMETA-INF/services/org.slf4j.spi.SLF4JServiceProvider\\E" }, { "pattern":"\\QMETA-INF/services/software.amazon.lambda.powertools.logging.internal.LoggingManager\\E" - }, { - "pattern":"\\Qcom/amazonaws/lambda/thirdparty/org/joda/time/tz/data/Europe/Berlin\\E" - }, { - "pattern":"\\Qcom/amazonaws/lambda/thirdparty/org/joda/time/tz/data/ZoneInfoMap\\E" }]}, "bundles":[] } 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 new file mode 100644 index 000000000..ea3a2f3f6 --- /dev/null +++ b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/PowertoolsLoggingTest.java @@ -0,0 +1,53 @@ +/* + * 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; + +import static org.assertj.core.api.Assertions.assertThat; + +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; + +import software.amazon.lambda.powertools.logging.internal.LoggingManagerRegistry; +import software.amazon.lambda.powertools.logging.internal.TestLoggingManager; + +class PowertoolsLoggingTest { + + private TestLoggingManager testManager; + + @BeforeEach + void setUp() { + // Get the TestLoggingManager instance from registry + testManager = (TestLoggingManager) LoggingManagerRegistry.getLoggingManager(); + testManager.resetBufferState(); + } + + @Test + void testFlushBuffer_shouldCallBufferManager() { + // WHEN + PowertoolsLogging.flushBuffer(); + + // THEN + assertThat(testManager.isBufferFlushed()).isTrue(); + } + + @Test + void testClearBuffer_shouldCallBufferManager() { + // WHEN + PowertoolsLogging.clearBuffer(); + + // THEN + assertThat(testManager.isBufferCleared()).isTrue(); + } +} diff --git a/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/handlers/PowertoolsLogErrorNoFlush.java b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/handlers/PowertoolsLogErrorNoFlush.java new file mode 100644 index 000000000..87515654c --- /dev/null +++ b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/handlers/PowertoolsLogErrorNoFlush.java @@ -0,0 +1,15 @@ +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 PowertoolsLogErrorNoFlush implements RequestHandler { + + @Override + @Logging(logError = true, flushBufferOnUncaughtError = false) + public String handleRequest(String input, Context context) { + throw new RuntimeException("This is an error without buffer flush"); + } +} diff --git a/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/KeyBufferTest.java b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/KeyBufferTest.java new file mode 100644 index 000000000..15a54fa5c --- /dev/null +++ b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/KeyBufferTest.java @@ -0,0 +1,356 @@ +/* + * 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.internal; + +import static org.assertj.core.api.Assertions.assertThat; + +import java.io.ByteArrayOutputStream; +import java.io.Closeable; +import java.io.IOException; +import java.io.PrintStream; +import java.nio.channels.FileChannel; +import java.nio.file.Paths; +import java.nio.file.StandardOpenOption; +import java.util.Deque; +import java.util.concurrent.CountDownLatch; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; +import java.util.concurrent.TimeUnit; + +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; + +class KeyBufferTest { + + private KeyBuffer buffer; + private static final int MAX_BYTES = 20; + + @BeforeEach + void setUp() throws IOException { + buffer = new KeyBuffer<>(MAX_BYTES, String::length); + // Clean up log file before each test + try { + FileChannel.open(Paths.get("target/logfile.json"), StandardOpenOption.WRITE).truncate(0).close(); + } catch (IOException e) { + // may not be there in the first run + } + } + + @AfterEach + void cleanUp() throws IOException { + // Make sure file is cleaned up after each test + FileChannel.open(Paths.get("target/logfile.json"), StandardOpenOption.WRITE).truncate(0).close(); + } + + @Test + void shouldAddEventToBuffer() { + buffer.add("key1", "test"); + + Deque events = buffer.removeAll("key1"); + assertThat(events).containsExactly("test"); + } + + @Test + void shouldMaintainSeparateBuffersPerKey() { + buffer.add("key1", "event1"); + buffer.add("key2", "event2"); + + Deque events1 = buffer.removeAll("key1"); + Deque events2 = buffer.removeAll("key2"); + + assertThat(events1).containsExactly("event1"); + assertThat(events2).containsExactly("event2"); + } + + @Test + void shouldMaintainFIFOOrder() { + buffer.add("key1", "first"); + buffer.add("key1", "second"); + buffer.add("key1", "third"); + + Deque events = buffer.removeAll("key1"); + assertThat(events).containsExactly("first", "second", "third"); + } + + @Test + void shouldEvictOldestEventsWhenBufferOverflows() { + // Add events that total exactly maxBytes + buffer.add("key1", "12345678901234567890"); // 20 bytes + + // Add another event that causes overflow + buffer.add("key1", "extra"); + + Deque events = buffer.removeAll("key1"); + assertThat(events).containsExactly("extra"); + } + + @Test + void shouldEvictMultipleEventsIfNeeded() { + buffer.add("key1", "1234567890"); // 10 bytes + buffer.add("key1", "1234567890"); // 10 bytes, total 20 + buffer.add("key1", "12345678901234567890"); // 20 bytes, should evict both previous + + Deque events = buffer.removeAll("key1"); + assertThat(events).containsExactly("12345678901234567890"); + } + + @Test + void shouldEvictMultipleSmallEventsForLargeValidEvent() { + // Add many small events that fill the buffer + buffer.add("key1", "12"); // 2 bytes + buffer.add("key1", "34"); // 2 bytes, total 4 + buffer.add("key1", "56"); // 2 bytes, total 6 + buffer.add("key1", "78"); // 2 bytes, total 8 + buffer.add("key1", "90"); // 2 bytes, total 10 + buffer.add("key1", "ab"); // 2 bytes, total 12 + buffer.add("key1", "cd"); // 2 bytes, total 14 + buffer.add("key1", "ef"); // 2 bytes, total 16 + buffer.add("key1", "gh"); // 2 bytes, total 18 + buffer.add("key1", "ij"); // 2 bytes, total 20 (exactly at limit) + + // Add a large event that requires multiple evictions + buffer.add("key1", "123456789012345678"); // 18 bytes, should evict multiple small events + + Deque events = buffer.removeAll("key1"); + // Should only contain the last few small events plus the large event + // 18 bytes for large event leaves 2 bytes, so only "ij" should remain with the large event + assertThat(events).containsExactly("ij", "123456789012345678"); + } + + @Test + void shouldRejectEventLargerThanMaxBytes() { + String largeEvent = "123456789012345678901"; // 21 bytes > 20 max + + buffer.add("key1", largeEvent); + + Deque events = buffer.removeAll("key1"); + assertThat(events).isNull(); + } + + @Test + void shouldNotEvictExistingEventsWhenRejectingLargeEvent() { + buffer.add("key1", "small"); + + String largeEvent = "123456789012345678901"; // 21 bytes > 20 max + buffer.add("key1", largeEvent); + + Deque events = buffer.removeAll("key1"); + assertThat(events).containsExactly("small"); + } + + @Test + void shouldClearSpecificKeyBuffer() { + buffer.add("key1", "event1"); + buffer.add("key2", "event2"); + + buffer.clear("key1"); + + assertThat(buffer.removeAll("key1")).isNull(); + assertThat(buffer.removeAll("key2")).containsExactly("event2"); + } + + @Test + void shouldReturnNullForNonExistentKey() { + Deque events = buffer.removeAll("nonexistent"); + assertThat(events).isNull(); + } + + @Test + void shouldReturnDefensiveCopyOnRemoveAll() { + buffer.add("key1", "event"); + + Deque events1 = buffer.removeAll("key1"); + buffer.add("key1", "event"); + Deque events2 = buffer.removeAll("key1"); + + // Modifying first copy shouldn't affect second + events1.add("modified"); + assertThat(events2).containsExactly("event"); + assertThat(events1).containsExactly("event", "modified"); + } + + @Test + void shouldLogWarningOnOverflow() { + StringBuilder warningCapture = new StringBuilder(); + KeyBuffer testBuffer = new KeyBuffer<>(10, String::length, + () -> warningCapture.append("Some logs are not displayed because they were evicted from the buffer")); + + // Cause overflow + testBuffer.add("key1", "1234567890"); // 10 bytes + testBuffer.add("key1", "extra"); // causes overflow + + // Trigger warning by removing + testBuffer.removeAll("key1"); + + assertThat(warningCapture.toString()) + .contains("Some logs are not displayed because they were evicted from the buffer"); + } + + @Test + void shouldLogWarningOnLargeEventRejection() { + StringBuilder warningCapture = new StringBuilder(); + KeyBuffer testBuffer = new KeyBuffer<>(10, String::length, + () -> warningCapture.append("Some logs are not displayed because they were evicted from the buffer")); + + // Add large event that gets rejected + testBuffer.add("key1", "12345678901"); // 11 bytes > 10 max + + // Trigger warning by removing + testBuffer.removeAll("key1"); + + assertThat(warningCapture.toString()) + .contains("Some logs are not displayed because they were evicted from the buffer"); + } + + @Test + void shouldNotLogWarningWhenNoOverflow() { + StringBuilder warningCapture = new StringBuilder(); + KeyBuffer testBuffer = new KeyBuffer<>(20, String::length, + () -> warningCapture.append("Some logs are not displayed because they were evicted from the buffer")); + + testBuffer.add("key1", "small"); + testBuffer.removeAll("key1"); + + assertThat(warningCapture.toString()) + .doesNotContain("Some logs are not displayed because they were evicted from the buffer"); + } + + @Test + void shouldBeThreadSafeForDifferentKeys() throws InterruptedException, IOException { + int threadCount = 10; + int eventsPerThread = 100; + KeyBuffer largeBuffer = new KeyBuffer<>(10000, String::length); + ExecutorService executor = Executors.newFixedThreadPool(threadCount); + try (Closeable ignored = executor::shutdown) { + CountDownLatch latch = new CountDownLatch(threadCount); + + // Each thread works with different key + for (int i = 0; i < threadCount; i++) { + final String key = "key" + i; + executor.submit(() -> { + try { + for (int j = 0; j < eventsPerThread; j++) { + largeBuffer.add(key, "event" + j); + } + } finally { + latch.countDown(); + } + }); + } + + assertThat(latch.await(5, TimeUnit.SECONDS)).isTrue(); + + // Verify each key has its events + for (int i = 0; i < threadCount; i++) { + String key = "key" + i; + Deque events = largeBuffer.removeAll(key); + assertThat(events) + .isNotNull() + .hasSize(eventsPerThread); + } + } + } + + @Test + void shouldBeThreadSafeForSameKey() throws InterruptedException, IOException { + int threadCount = 5; + int eventsPerThread = 20; + KeyBuffer largeBuffer = new KeyBuffer<>(10000, String::length); + ExecutorService executor = Executors.newFixedThreadPool(threadCount); + try (Closeable ignored = executor::shutdown) { + CountDownLatch latch = new CountDownLatch(threadCount); + + // All threads work with same key + for (int i = 0; i < threadCount; i++) { + final int threadId = i; + executor.submit(() -> { + try { + for (int j = 0; j < eventsPerThread; j++) { + largeBuffer.add("sharedKey", "t" + threadId + "e" + j); + } + } finally { + latch.countDown(); + } + }); + } + + assertThat(latch.await(5, TimeUnit.SECONDS)).isTrue(); + + Deque events = largeBuffer.removeAll("sharedKey"); + assertThat(events) + .isNotNull() + .hasSize(threadCount * eventsPerThread); + } + } + + @Test + void shouldHandleEmptyBuffer() { + buffer.clear("nonexistent"); + assertThat(buffer.removeAll("nonexistent")).isNull(); + } + + @Test + void shouldHandleZeroSizeEvents() { + KeyBuffer zeroBuffer = new KeyBuffer<>(10, s -> 0); + + zeroBuffer.add("key1", "event1"); + zeroBuffer.add("key1", "event2"); + + Deque events = zeroBuffer.removeAll("key1"); + assertThat(events).containsExactly("event1", "event2"); + } + + @Test + void shouldUseCustomWarningLogger() { + StringBuilder customWarning = new StringBuilder(); + KeyBuffer testBuffer = new KeyBuffer<>(5, String::length, + () -> customWarning.append("CUSTOM WARNING LOGGED")); + + // Cause overflow + testBuffer.add("key1", "12345"); // 5 bytes + testBuffer.add("key1", "extra"); // causes overflow + + // Trigger warning + testBuffer.removeAll("key1"); + + assertThat(customWarning).hasToString("CUSTOM WARNING LOGGED"); + } + + @Test + void shouldUseDefaultWarningLoggerWhenNotProvided() { + // Capture System.err output + ByteArrayOutputStream errCapture = new ByteArrayOutputStream(); + @SuppressWarnings("PMD.CloseResource") // System.err is not ours to close + PrintStream originalErr = System.err; + try (PrintStream newErr = new PrintStream(errCapture)) { + System.setErr(newErr); + + KeyBuffer defaultBuffer = new KeyBuffer<>(5, String::length); + + // Cause overflow + defaultBuffer.add("key1", "12345"); + defaultBuffer.add("key1", "extra"); + defaultBuffer.removeAll("key1"); + + // Assert System.err received the warning + assertThat(errCapture) + .hasToString( + "WARN [KeyBuffer] - Some logs are not displayed because they were evicted from the buffer. Increase buffer size to store more logs in the buffer.\n"); + } finally { + System.setErr(originalErr); + } + } +} 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 751d195b5..3ff531321 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.io.PrintStream; -import java.io.UnsupportedEncodingException; import java.lang.reflect.InvocationTargetException; import java.lang.reflect.Method; import java.nio.channels.FileChannel; @@ -40,7 +38,6 @@ import java.nio.file.NoSuchFileException; import java.nio.file.Paths; import java.nio.file.StandardOpenOption; -import java.util.ArrayList; import java.util.Collections; import java.util.List; import java.util.Map; @@ -81,6 +78,7 @@ import software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEnabled; import software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEnabledForStream; import software.amazon.lambda.powertools.logging.handlers.PowertoolsLogError; +import software.amazon.lambda.powertools.logging.handlers.PowertoolsLogErrorNoFlush; import software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEvent; import software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEventBridgeCorrelationId; import software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEventEnvVar; @@ -111,6 +109,13 @@ void setUp() throws IllegalAccessException, NoSuchMethodException, InvocationTar writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_LEVEL", null, true); writeStaticField(LoggingConstants.class, "POWERTOOLS_LOG_EVENT", false, true); writeStaticField(LoggingConstants.class, "POWERTOOLS_SAMPLING_RATE", null, true); + + // Reset buffer state for clean test isolation + LoggingManager loggingManager = LoggingManagerRegistry.getLoggingManager(); + if (loggingManager instanceof TestLoggingManager) { + ((TestLoggingManager) loggingManager).resetBufferState(); + } + try { FileChannel.open(Paths.get("target/logfile.json"), StandardOpenOption.WRITE).truncate(0).close(); } catch (NoSuchFileException e) { @@ -721,47 +726,129 @@ void shouldLogCorrelationIdOnAppSyncEvent() throws IOException { } @Test - void testMultipleLoggingManagers_shouldWarnAndSelectFirstOne() throws UnsupportedEncodingException { - // GIVEN - List list = new ArrayList<>(); - list.add(new TestLoggingManager()); - list.add(new DefautlLoggingManager()); + void shouldClearBufferAfterSuccessfulHandlerExecution() { + // WHEN + requestHandler.handleRequest(new Object(), context); - ByteArrayOutputStream outputStream = new ByteArrayOutputStream(); - PrintStream stream = new PrintStream(outputStream); + // THEN + LoggingManager loggingManager = LoggingManagerRegistry.getLoggingManager(); + if (loggingManager instanceof TestLoggingManager) { + assertThat(((TestLoggingManager) loggingManager).isBufferCleared()).isTrue(); + } + } + @Test + void shouldClearBufferAfterSuccessfulStreamHandlerExecution() throws IOException { // WHEN - LambdaLoggingAspect.getLoggingManager(list, stream); + requestStreamHandler.handleRequest(new ByteArrayInputStream(new byte[] {}), new ByteArrayOutputStream(), + context); // THEN - String output = outputStream.toString("UTF-8"); - assertThat(output) - .contains("WARN. Multiple LoggingManagers were found on the classpath") - .contains( - "WARN. Make sure to have only one of powertools-logging-log4j OR powertools-logging-logback to your dependencies") - .contains("WARN. Using the first LoggingManager found on the classpath: [" + list.get(0) + "]"); + LoggingManager loggingManager = LoggingManagerRegistry.getLoggingManager(); + if (loggingManager instanceof TestLoggingManager) { + assertThat(((TestLoggingManager) loggingManager).isBufferCleared()).isTrue(); + } + } + + @Test + void shouldClearBufferAfterHandlerExceptionWithLogError() { + // GIVEN + requestHandler = new PowertoolsLogError(); + + // WHEN + try { + requestHandler.handleRequest("input", context); + } catch (Exception e) { + // ignore + } + + // THEN + LoggingManager loggingManager = LoggingManagerRegistry.getLoggingManager(); + if (loggingManager instanceof TestLoggingManager) { + assertThat(((TestLoggingManager) loggingManager).isBufferCleared()).isTrue(); + } + } + + @Test + void shouldClearBufferAfterHandlerExceptionWithEnvVarLogError() { + try { + // GIVEN + LoggingConstants.POWERTOOLS_LOG_ERROR = true; + requestHandler = new PowertoolsLogEnabled(true); + + // WHEN + try { + requestHandler.handleRequest("input", context); + } catch (Exception e) { + // ignore + } + + // THEN + LoggingManager loggingManager = LoggingManagerRegistry.getLoggingManager(); + if (loggingManager instanceof TestLoggingManager) { + assertThat(((TestLoggingManager) loggingManager).isBufferCleared()).isTrue(); + } + } finally { + LoggingConstants.POWERTOOLS_LOG_ERROR = false; + } } @Test - void testNoLoggingManagers_shouldWarnAndCreateDefault() throws UnsupportedEncodingException { + void shouldFlushBufferOnUncaughtErrorWhenEnabled() { // GIVEN - List list = new ArrayList<>(); + requestHandler = new PowertoolsLogError(); - ByteArrayOutputStream outputStream = new ByteArrayOutputStream(); - PrintStream stream = new PrintStream(outputStream); + // WHEN + try { + requestHandler.handleRequest("input", context); + } catch (Exception e) { + // ignore + } + + // THEN + LoggingManager loggingManager = LoggingManagerRegistry.getLoggingManager(); + if (loggingManager instanceof TestLoggingManager) { + assertThat(((TestLoggingManager) loggingManager).isBufferFlushed()).isTrue(); + } + } + + @Test + void shouldNotFlushBufferOnUncaughtErrorWhenDisabled() { + // GIVEN + PowertoolsLogErrorNoFlush handler = new PowertoolsLogErrorNoFlush(); // WHEN - LoggingManager loggingManager = LambdaLoggingAspect.getLoggingManager(list, stream); + try { + handler.handleRequest("input", context); + } catch (Exception e) { + // ignore + } // THEN - String output = outputStream.toString("UTF-8"); - assertThat(output) - .contains("ERROR. No LoggingManager was found on the classpath") - .contains("ERROR. Applying default LoggingManager: POWERTOOLS_LOG_LEVEL variable is ignored") - .contains( - "ERROR. Make sure to add either powertools-logging-log4j or powertools-logging-logback to your dependencies"); + LoggingManager loggingManager = LoggingManagerRegistry.getLoggingManager(); + if (loggingManager instanceof TestLoggingManager) { + assertThat(((TestLoggingManager) loggingManager).isBufferFlushed()).isFalse(); + } + } - assertThat(loggingManager).isExactlyInstanceOf(DefautlLoggingManager.class); + @Test + void shouldClearBufferBeforeErrorLoggingWhenFlushBufferOnUncaughtErrorDisabled() { + // GIVEN + PowertoolsLogErrorNoFlush handler = new PowertoolsLogErrorNoFlush(); + + // WHEN + try { + handler.handleRequest("input", context); + } catch (Exception e) { + // ignore + } + + // THEN - Buffer should be cleared and not flushed + LoggingManager loggingManager = LoggingManagerRegistry.getLoggingManager(); + if (loggingManager instanceof TestLoggingManager) { + assertThat(((TestLoggingManager) loggingManager).isBufferCleared()).isTrue(); + assertThat(((TestLoggingManager) loggingManager).isBufferFlushed()).isFalse(); + } } private void resetLogLevel(Level level) diff --git a/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/LoggingManagerRegistryTest.java b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/LoggingManagerRegistryTest.java new file mode 100644 index 000000000..6bed0d9c1 --- /dev/null +++ b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/LoggingManagerRegistryTest.java @@ -0,0 +1,141 @@ +/* + * 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.internal; + +import static org.assertj.core.api.Assertions.assertThat; + +import java.io.ByteArrayOutputStream; +import java.io.Closeable; +import java.io.IOException; +import java.io.PrintStream; +import java.io.UnsupportedEncodingException; +import java.util.ArrayList; +import java.util.List; +import java.util.concurrent.CountDownLatch; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicReference; + +import org.junit.jupiter.api.Test; + +class LoggingManagerRegistryTest { + + @Test + void testMultipleLoggingManagers_shouldWarnAndSelectFirstOne() throws UnsupportedEncodingException { + // GIVEN + List list = new ArrayList<>(); + list.add(new TestLoggingManager()); + list.add(new DefaultLoggingManager()); + + ByteArrayOutputStream outputStream = new ByteArrayOutputStream(); + PrintStream stream = new PrintStream(outputStream); + + // WHEN + LoggingManagerRegistry.selectLoggingManager(list, stream); + + // THEN + String output = outputStream.toString("UTF-8"); + assertThat(output) + .contains("WARN. Multiple LoggingManagers were found on the classpath") + .contains( + "WARN. Make sure to have only one of powertools-logging-log4j OR powertools-logging-logback in your dependencies") + .contains("WARN. Using the first LoggingManager found on the classpath: [" + list.get(0) + "]"); + } + + @Test + void testNoLoggingManagers_shouldWarnAndCreateDefault() throws UnsupportedEncodingException { + // GIVEN + List list = new ArrayList<>(); + + ByteArrayOutputStream outputStream = new ByteArrayOutputStream(); + PrintStream stream = new PrintStream(outputStream); + + // WHEN + LoggingManager loggingManager = LoggingManagerRegistry.selectLoggingManager(list, stream); + + // THEN + String output = outputStream.toString("UTF-8"); + assertThat(output) + .contains("ERROR. No LoggingManager was found on the classpath") + .contains("ERROR. Applying default LoggingManager: POWERTOOLS_LOG_LEVEL variable is ignored") + .contains( + "ERROR. Make sure to add either powertools-logging-log4j or powertools-logging-logback to your dependencies"); + + assertThat(loggingManager).isExactlyInstanceOf(DefaultLoggingManager.class); + } + + @Test + void testSingleLoggingManager_shouldReturnWithoutWarning() throws UnsupportedEncodingException { + // GIVEN + List list = new ArrayList<>(); + TestLoggingManager testManager = new TestLoggingManager(); + list.add(testManager); + + ByteArrayOutputStream outputStream = new ByteArrayOutputStream(); + PrintStream stream = new PrintStream(outputStream); + + // WHEN + LoggingManager loggingManager = LoggingManagerRegistry.selectLoggingManager(list, stream); + + // THEN + String output = outputStream.toString("UTF-8"); + assertThat(output).isEmpty(); + assertThat(loggingManager) + .isSameAs(testManager) + .isInstanceOf(BufferManager.class); + } + + @Test + void testGetLoggingManager_shouldReturnSameInstance() { + // WHEN + LoggingManager first = LoggingManagerRegistry.getLoggingManager(); + LoggingManager second = LoggingManagerRegistry.getLoggingManager(); + + // THEN + assertThat(first) + .isSameAs(second) + .isNotNull() + .isInstanceOf(BufferManager.class); + } + + @Test + void testGetLoggingManager_shouldBeThreadSafe() throws InterruptedException, IOException { + // GIVEN + int threadCount = 10; + ExecutorService executor = Executors.newFixedThreadPool(threadCount); + try (Closeable ignored = executor::shutdown) { + CountDownLatch latch = new CountDownLatch(threadCount); + AtomicReference sharedInstance = new AtomicReference<>(); + + // WHEN + for (int i = 0; i < threadCount; i++) { + executor.submit(() -> { + try { + LoggingManager instance = LoggingManagerRegistry.getLoggingManager(); + sharedInstance.compareAndSet(null, instance); + assertThat(instance).isSameAs(sharedInstance.get()); + } finally { + latch.countDown(); + } + }); + } + + // THEN + latch.await(5, TimeUnit.SECONDS); + assertThat(sharedInstance.get()).isNotNull(); + } + } +} diff --git a/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/TestLoggingManager.java b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/TestLoggingManager.java index 0958e0d3b..f2aa2417e 100644 --- a/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/TestLoggingManager.java +++ b/powertools-logging/src/test/java/software/amazon/lambda/powertools/logging/internal/TestLoggingManager.java @@ -7,17 +7,19 @@ import org.slf4j.test.TestLogger; import org.slf4j.test.TestLoggerFactory; -public class TestLoggingManager implements LoggingManager { +public class TestLoggingManager implements LoggingManager, BufferManager { private final TestLoggerFactory loggerFactory; + private boolean bufferFlushed = false; + private boolean bufferCleared = false; public TestLoggingManager() { - ILoggerFactory loggerFactory = LoggerFactory.getILoggerFactory(); - if (!(loggerFactory instanceof TestLoggerFactory)) { + ILoggerFactory loggerFactoryInstance = LoggerFactory.getILoggerFactory(); + if (!(loggerFactoryInstance instanceof TestLoggerFactory)) { throw new RuntimeException( "LoggerFactory does not match required type: " + TestLoggerFactory.class.getName()); } - this.loggerFactory = (TestLoggerFactory) loggerFactory; + this.loggerFactory = (TestLoggerFactory) loggerFactoryInstance; } @Override @@ -29,4 +31,27 @@ public void setLogLevel(Level logLevel) { public Level getLogLevel(Logger logger) { return org.slf4j.event.Level.intToLevel(((TestLogger) logger).getLogLevel()); } + + @Override + public void flushBuffer() { + bufferFlushed = true; + } + + @Override + public void clearBuffer() { + bufferCleared = true; + } + + public boolean isBufferFlushed() { + return bufferFlushed; + } + + public boolean isBufferCleared() { + return bufferCleared; + } + + public void resetBufferState() { + bufferFlushed = false; + bufferCleared = false; + } }