Skip to content

Commit d439ba4

Browse files
phipagphipag
committed
Add developer documentation.
1 parent c6d55d6 commit d439ba4

File tree

1 file changed

+374
-4
lines changed

1 file changed

+374
-4
lines changed

‎docs/core/logging.md‎

Lines changed: 374 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,7 @@ Logging provides an opinionated logger with output structured as JSON.
1212
* Optionally logs Lambda request
1313
* Optionally logs Lambda response
1414
* Optionally supports log sampling by including a configurable percentage of DEBUG logs in logging output
15+
* Optionally supports buffering lower level logs and flushing them on error or manually
1516
* Allows additional keys to be appended to the structured log at any point in time
1617
* GraalVM support
1718

@@ -311,9 +312,8 @@ We prioritise log level settings in this order:
311312

312313
If you set `POWERTOOLS_LOG_LEVEL` lower than ALC, we will emit a warning informing you that your messages will be discarded by Lambda.
313314

314-
> **NOTE**
315-
>
316-
> 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.
315+
!!! note
316+
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.
317317

318318
## Basic Usage
319319

@@ -787,7 +787,377 @@ with `logError` param or via `POWERTOOLS_LOGGER_LOG_ERROR` env var.
787787
}
788788
```
789789

790-
# Advanced
790+
## Advanced
791+
792+
### Buffering logs
793+
794+
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.
795+
796+
!!! 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."
797+
798+
=== "log4j2.xml"
799+
800+
```xml hl_lines="7-12 16 19"
801+
<?xml version="1.0" encoding="UTF-8"?>
802+
<Configuration>
803+
<Appenders>
804+
<Console name="JsonAppender" target="SYSTEM_OUT">
805+
<JsonTemplateLayout eventTemplateUri="classpath:LambdaJsonLayout.json" />
806+
</Console>
807+
<BufferingAppender name="BufferedJsonAppender"
808+
maxBytes="20480"
809+
bufferAtVerbosity="DEBUG"
810+
flushOnErrorLog="true">
811+
<AppenderRef ref="JsonAppender"/>
812+
</BufferingAppender>
813+
</Appenders>
814+
<Loggers>
815+
<Logger name="com.example" level="debug" additivity="false">
816+
<AppenderRef ref="BufferedJsonAppender"/>
817+
</Logger>
818+
<Root level="debug">
819+
<AppenderRef ref="BufferedJsonAppender"/>
820+
</Root>
821+
</Loggers>
822+
</Configuration>
823+
```
824+
825+
=== "logback.xml"
826+
827+
```xml hl_lines="6-11 13 16"
828+
<?xml version="1.0" encoding="UTF-8"?>
829+
<configuration>
830+
<appender name="JsonAppender" class="ch.qos.logback.core.ConsoleAppender">
831+
<encoder class="software.amazon.lambda.powertools.logging.logback.LambdaJsonEncoder" />
832+
</appender>
833+
<appender name="BufferedJsonAppender" class="software.amazon.lambda.powertools.logging.logback.BufferingAppender">
834+
<maxBytes>20480</maxBytes>
835+
<bufferAtVerbosity>DEBUG</bufferAtVerbosity>
836+
<flushOnErrorLog>true</flushOnErrorLog>
837+
<appender-ref ref="JsonAppender" />
838+
</appender>
839+
<logger name="com.example" level="DEBUG" additivity="false">
840+
<appender-ref ref="BufferedJsonAppender" />
841+
</logger>
842+
<root level="DEBUG">
843+
<appender-ref ref="BufferedJsonAppender" />
844+
</root>
845+
</configuration>
846+
```
847+
848+
=== "PaymentFunction.java"
849+
850+
```java hl_lines="8 12"
851+
import org.slf4j.Logger;
852+
import org.slf4j.LoggerFactory;
853+
import software.amazon.lambda.powertools.logging.Logging;
854+
// ... other imports
855+
856+
public class PaymentFunction implements RequestHandler<APIGatewayProxyRequestEvent, APIGatewayProxyResponseEvent> {
857+
858+
private static final Logger LOGGER = LoggerFactory.getLogger(PaymentFunction.class);
859+
860+
@Logging
861+
public APIGatewayProxyResponseEvent handleRequest(final APIGatewayProxyRequestEvent input, final Context context) {
862+
LOGGER.debug("a debug log"); // this is buffered
863+
LOGGER.info("an info log"); // this is not buffered
864+
865+
// do stuff
866+
867+
// Buffer is automatically cleared at the end of the method by @Logging annotation
868+
return new APIGatewayProxyResponseEvent().withStatusCode(200);
869+
}
870+
}
871+
```
872+
873+
#### Configuring the buffer
874+
875+
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:
876+
877+
| Parameter | Description | Configuration |
878+
| --------------------- | ----------------------------------------------- | ---------------------------- |
879+
| `maxBytes` | Maximum size of the log buffer in bytes | `int` (default: 20480 bytes) |
880+
| `bufferAtVerbosity` | Minimum log level to buffer | `DEBUG` (default), `INFO`, `WARNING` |
881+
| `flushOnErrorLog` | Automatically flush buffer when `ERROR` or `FATAL` level logs are emitted | `true` (default), `false` |
882+
883+
!!! warning "Logger Level Configuration"
884+
To use log buffering effectively, you must set your logger levels to the most verbose level (`DEBUG`) so that all logs can be captured by the `BufferingAppender`. The `BufferingAppender` then decides which logs to buffer based on the `bufferAtVerbosity` setting.
885+
886+
- Set your logger levels to `DEBUG` in your log4j2.xml or logback.xml configuration
887+
- Set `POWERTOOLS_LOG_LEVEL=DEBUG` if using the environment variable (see [Log level](#log-level) section for more details)
888+
889+
This ensures that all log levels (`DEBUG`, `INFO`, `WARN`) are forwarded to the `BufferingAppender` for it to selectively buffer or emit directly.
890+
891+
=== "log4j2.xml - Buffer at WARNING level"
892+
893+
```xml hl_lines="9 14-15 18"
894+
<?xml version="1.0" encoding="UTF-8"?>
895+
<Configuration>
896+
<Appenders>
897+
<Console name="JsonAppender" target="SYSTEM_OUT">
898+
<JsonTemplateLayout eventTemplateUri="classpath:LambdaJsonLayout.json" />
899+
</Console>
900+
<BufferingAppender name="BufferedJsonAppender"
901+
maxBytes="20480"
902+
bufferAtVerbosity="WARNING">
903+
<AppenderRef ref="JsonAppender"/>
904+
</BufferingAppender>
905+
</Appenders>
906+
<Loggers>
907+
<!-- Intentionally set to DEBUG to forward all logs to BufferingAppender -->
908+
<Logger name="com.example" level="debug" additivity="false">
909+
<AppenderRef ref="BufferedJsonAppender"/>
910+
</Logger>
911+
<Root level="debug">
912+
<AppenderRef ref="BufferedJsonAppender"/>
913+
</Root>
914+
</Loggers>
915+
</Configuration>
916+
```
917+
918+
=== "PaymentFunction.java - Buffer at WARNING level"
919+
920+
```java hl_lines="7-9 13"
921+
public class PaymentFunction implements RequestHandler<APIGatewayProxyRequestEvent, APIGatewayProxyResponseEvent> {
922+
923+
private static final Logger LOGGER = LoggerFactory.getLogger(PaymentFunction.class);
924+
925+
@Logging
926+
public APIGatewayProxyResponseEvent handleRequest(final APIGatewayProxyRequestEvent input, final Context context) {
927+
LOGGER.warn("a warning log"); // this is buffered
928+
LOGGER.info("an info log"); // this is buffered
929+
LOGGER.debug("a debug log"); // this is buffered
930+
931+
// do stuff
932+
933+
// Buffer is automatically cleared at the end of the method by @Logging annotation
934+
return new APIGatewayProxyResponseEvent().withStatusCode(200);
935+
}
936+
}
937+
```
938+
939+
=== "log4j2.xml - Disable flush on error"
940+
941+
```xml hl_lines="9"
942+
<?xml version="1.0" encoding="UTF-8"?>
943+
<Configuration>
944+
<Appenders>
945+
<Console name="JsonAppender" target="SYSTEM_OUT">
946+
<JsonTemplateLayout eventTemplateUri="classpath:LambdaJsonLayout.json" />
947+
</Console>
948+
<BufferingAppender name="BufferedJsonAppender"
949+
maxBytes="20480"
950+
flushOnErrorLog="false">
951+
<AppenderRef ref="JsonAppender"/>
952+
</BufferingAppender>
953+
</Appenders>
954+
<Loggers>
955+
<Logger name="com.example" level="debug" additivity="false">
956+
<AppenderRef ref="BufferedJsonAppender"/>
957+
</Logger>
958+
<Root level="debug">
959+
<AppenderRef ref="BufferedJsonAppender"/>
960+
</Root>
961+
</Loggers>
962+
</Configuration>
963+
```
964+
965+
=== "PaymentFunction.java - Manual flush required"
966+
967+
```java hl_lines="1 16 19-20"
968+
import software.amazon.lambda.powertools.logging.PowertoolsLogging;
969+
970+
public class PaymentFunction implements RequestHandler<APIGatewayProxyRequestEvent, APIGatewayProxyResponseEvent> {
971+
972+
private static final Logger LOGGER = LoggerFactory.getLogger(PaymentFunction.class);
973+
974+
@Logging
975+
public APIGatewayProxyResponseEvent handleRequest(final APIGatewayProxyRequestEvent input, final Context context) {
976+
LOGGER.debug("a debug log"); // this is buffered
977+
978+
// do stuff
979+
980+
try {
981+
throw new RuntimeException("Something went wrong");
982+
} catch (RuntimeException error) {
983+
LOGGER.error("An error occurred", error); // Logs won't be flushed here
984+
}
985+
986+
// Manually flush buffered logs
987+
PowertoolsLogging.flushBuffer();
988+
989+
return new APIGatewayProxyResponseEvent().withStatusCode(200);
990+
}
991+
}
992+
```
993+
994+
!!! 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."
995+
996+
#### Manual buffer control
997+
998+
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:
999+
1000+
=== "Manual flush"
1001+
1002+
```java hl_lines="1 12-13"
1003+
import software.amazon.lambda.powertools.logging.PowertoolsLogging;
1004+
1005+
public class PaymentFunction implements RequestHandler<APIGatewayProxyRequestEvent, APIGatewayProxyResponseEvent> {
1006+
1007+
private static final Logger LOGGER = LoggerFactory.getLogger(PaymentFunction.class);
1008+
1009+
@Logging
1010+
public APIGatewayProxyResponseEvent handleRequest(final APIGatewayProxyRequestEvent input, final Context context) {
1011+
LOGGER.debug("Processing payment"); // this is buffered
1012+
LOGGER.info("Payment validation complete"); // this is buffered
1013+
1014+
// Manually flush all buffered logs
1015+
PowertoolsLogging.flushBuffer();
1016+
1017+
return new APIGatewayProxyResponseEvent().withStatusCode(200);
1018+
}
1019+
}
1020+
```
1021+
1022+
=== "Manual clear"
1023+
1024+
```java hl_lines="1 12-13"
1025+
import software.amazon.lambda.powertools.logging.PowertoolsLogging;
1026+
1027+
public class PaymentFunction implements RequestHandler<APIGatewayProxyRequestEvent, APIGatewayProxyResponseEvent> {
1028+
1029+
private static final Logger LOGGER = LoggerFactory.getLogger(PaymentFunction.class);
1030+
1031+
@Logging
1032+
public APIGatewayProxyResponseEvent handleRequest(final APIGatewayProxyRequestEvent input, final Context context) {
1033+
LOGGER.debug("Processing payment"); // this is buffered
1034+
LOGGER.info("Payment validation complete"); // this is buffered
1035+
1036+
// Manually clear buffered logs without outputting them
1037+
PowertoolsLogging.clearBuffer();
1038+
1039+
return new APIGatewayProxyResponseEvent().withStatusCode(200);
1040+
}
1041+
}
1042+
```
1043+
1044+
**Available methods:**
1045+
1046+
- `#!java PowertoolsLogging.flushBuffer()` - Outputs all buffered logs and clears the buffer
1047+
- `#!java PowertoolsLogging.clearBuffer()` - Discards all buffered logs without outputting them
1048+
1049+
#### Flushing on exceptions
1050+
1051+
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.
1052+
1053+
=== "PaymentFunction.java"
1054+
1055+
```java hl_lines="5 11"
1056+
public class PaymentFunction implements RequestHandler<APIGatewayProxyRequestEvent, APIGatewayProxyResponseEvent> {
1057+
1058+
private static final Logger LOGGER = LoggerFactory.getLogger(PaymentFunction.class);
1059+
1060+
@Logging(flushBufferOnUncaughtError = true)
1061+
public APIGatewayProxyResponseEvent handleRequest(final APIGatewayProxyRequestEvent input, final Context context) {
1062+
LOGGER.debug("a debug log"); // this is buffered
1063+
1064+
// do stuff
1065+
1066+
throw new RuntimeException("Something went wrong"); // Logs will be flushed here
1067+
}
1068+
}
1069+
```
1070+
1071+
#### Buffering workflows
1072+
1073+
##### Manual flush
1074+
1075+
<center>
1076+
```mermaid
1077+
sequenceDiagram
1078+
participant Client
1079+
participant Lambda
1080+
participant Logger
1081+
participant CloudWatch
1082+
Client->>Lambda: Invoke Lambda
1083+
Lambda->>Logger: Initialize with DEBUG level buffering
1084+
Logger-->>Lambda: Logger buffer ready
1085+
Lambda->>Logger: logger.debug("First debug log")
1086+
Logger-->>Logger: Buffer first debug log
1087+
Lambda->>Logger: logger.info("Info log")
1088+
Logger->>CloudWatch: Directly log info message
1089+
Lambda->>Logger: logger.debug("Second debug log")
1090+
Logger-->>Logger: Buffer second debug log
1091+
Lambda->>Logger: Manual flush call
1092+
Logger->>CloudWatch: Emit buffered logs to stdout
1093+
Lambda->>Client: Return execution result
1094+
```
1095+
<i>Flushing buffer manually</i>
1096+
</center>
1097+
1098+
##### Flushing when logging an error
1099+
1100+
<center>
1101+
```mermaid
1102+
sequenceDiagram
1103+
participant Client
1104+
participant Lambda
1105+
participant Logger
1106+
participant CloudWatch
1107+
Client->>Lambda: Invoke Lambda
1108+
Lambda->>Logger: Initialize with DEBUG level buffering
1109+
Logger-->>Lambda: Logger buffer ready
1110+
Lambda->>Logger: logger.debug("First log")
1111+
Logger-->>Logger: Buffer first debug log
1112+
Lambda->>Logger: logger.debug("Second log")
1113+
Logger-->>Logger: Buffer second debug log
1114+
Lambda->>Logger: logger.debug("Third log")
1115+
Logger-->>Logger: Buffer third debug log
1116+
Lambda->>Lambda: Exception occurs
1117+
Lambda->>Logger: logger.error("Error details")
1118+
Logger->>CloudWatch: Emit error log
1119+
Logger->>CloudWatch: Emit buffered debug logs
1120+
Lambda->>Client: Raise exception
1121+
```
1122+
<i>Flushing buffer when an error happens</i>
1123+
</center>
1124+
1125+
##### Flushing on exception
1126+
1127+
This works when using the `@Logging` annotation which automatically clears the buffer at the end of method execution.
1128+
1129+
<center>
1130+
```mermaid
1131+
sequenceDiagram
1132+
participant Client
1133+
participant Lambda
1134+
participant Logger
1135+
participant CloudWatch
1136+
Client->>Lambda: Invoke Lambda
1137+
Lambda->>Logger: Using @Logging annotation
1138+
Logger-->>Lambda: Logger context injected
1139+
Lambda->>Logger: logger.debug("First log")
1140+
Logger-->>Logger: Buffer first debug log
1141+
Lambda->>Logger: logger.debug("Second log")
1142+
Logger-->>Logger: Buffer second debug log
1143+
Lambda->>Lambda: Uncaught Exception
1144+
Lambda->>CloudWatch: Automatically emit buffered debug logs
1145+
Lambda->>Client: Raise uncaught exception
1146+
```
1147+
<i>Flushing buffer when an uncaught exception happens</i>
1148+
</center>
1149+
1150+
#### Buffering FAQs
1151+
1152+
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.
1153+
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.
1154+
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 and consume excessive memory.
1155+
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.
1156+
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.
1157+
6. **What timestamp is used when I flush the logs?** The timestamp preserves 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.
1158+
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.
1159+
8. **What happens if Lambda times out without flushing the buffer?** Logs that are still in the buffer will be lost.
1160+
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.
7911161

7921162
## Sampling debug logs
7931163

0 commit comments

Comments
 (0)