Skip to content

Commit 59011e5

Browse files
committed
Log buffer PoC with log4j2 appender implementation.
1 parent 65f00fe commit 59011e5

File tree

18 files changed

+687
-197
lines changed

18 files changed

+687
-197
lines changed

examples/powertools-examples-core-utilities/sam/src/main/java/helloworld/App.java

Lines changed: 20 additions & 55 deletions
Original file line numberDiff line numberDiff line change
@@ -14,16 +14,8 @@
1414

1515
package helloworld;
1616

17-
import static software.amazon.lambda.powertools.logging.argument.StructuredArguments.entry;
18-
import static software.amazon.lambda.powertools.tracing.TracingUtils.putMetadata;
19-
20-
import java.io.BufferedReader;
21-
import java.io.IOException;
22-
import java.io.InputStreamReader;
23-
import java.net.URL;
2417
import java.util.HashMap;
2518
import java.util.Map;
26-
import java.util.stream.Collectors;
2719

2820
import org.slf4j.Logger;
2921
import org.slf4j.LoggerFactory;
@@ -35,79 +27,52 @@
3527
import com.amazonaws.services.lambda.runtime.events.APIGatewayProxyResponseEvent;
3628

3729
import software.amazon.lambda.powertools.logging.Logging;
38-
import software.amazon.lambda.powertools.metrics.FlushMetrics;
39-
import software.amazon.lambda.powertools.metrics.Metrics;
40-
import software.amazon.lambda.powertools.metrics.MetricsFactory;
41-
import software.amazon.lambda.powertools.metrics.model.DimensionSet;
42-
import software.amazon.lambda.powertools.metrics.model.MetricResolution;
43-
import software.amazon.lambda.powertools.metrics.model.MetricUnit;
44-
import software.amazon.lambda.powertools.tracing.CaptureMode;
45-
import software.amazon.lambda.powertools.tracing.Tracing;
46-
import software.amazon.lambda.powertools.tracing.TracingUtils;
30+
import software.amazon.lambda.powertools.logging.PowertoolsLogging;
4731

4832
/**
4933
* Handler for requests to Lambda function.
5034
*/
5135
public class App implements RequestHandler<APIGatewayProxyRequestEvent, APIGatewayProxyResponseEvent> {
5236
private static final Logger log = LoggerFactory.getLogger(App.class);
53-
private static final Metrics metrics = MetricsFactory.getMetricsInstance();
5437

55-
@Logging(logEvent = true, samplingRate = 0.7)
56-
@Tracing(captureMode = CaptureMode.RESPONSE_AND_ERROR)
57-
@FlushMetrics(namespace = "ServerlessAirline", service = "payment", captureColdStart = true)
38+
public App() {
39+
// Flush immediately because no trace ID is set yet
40+
log.debug("Constructor DEBUG - should not be buffered (no trace ID)");
41+
log.info("Constructor INFO - should not be buffered (no trace ID)");
42+
}
43+
44+
@Logging(logEvent = false)
5845
public APIGatewayProxyResponseEvent handleRequest(final APIGatewayProxyRequestEvent input, final Context context) {
46+
// Manually set trace ID for testing in SAM local
47+
System.setProperty("com.amazonaws.xray.traceHeader",
48+
"Root=1-63441c4a-abcdef012345678912345678;Parent=0123456789abcdef;Sampled=1");
49+
5950
Map<String, String> headers = new HashMap<>();
6051

6152
headers.put("Content-Type", "application/json");
6253
headers.put("X-Custom-Header", "application/json");
6354

64-
metrics.addMetric("CustomMetric1", 1, MetricUnit.COUNT);
65-
66-
DimensionSet dimensionSet = new DimensionSet();
67-
dimensionSet.addDimension("AnotherService", "CustomService");
68-
dimensionSet.addDimension("AnotherService1", "CustomService1");
69-
metrics.flushSingleMetric("CustomMetric2", 1, MetricUnit.COUNT, "Another", dimensionSet);
70-
71-
metrics.addMetric("CustomMetric3", 1, MetricUnit.COUNT, MetricResolution.HIGH);
72-
55+
log.debug("DEBUG 1");
7356
MDC.put("test", "willBeLogged");
57+
log.debug("DEBUG 2");
58+
log.info("INFO 1");
59+
60+
// Manually flush buffer to show buffered debug logs
61+
PowertoolsLogging.flushBuffer();
7462

7563
APIGatewayProxyResponseEvent response = new APIGatewayProxyResponseEvent()
7664
.withHeaders(headers);
7765
try {
78-
final String pageContents = this.getPageContents("https://checkip.amazonaws.com");
79-
log.info("", entry("ip", pageContents));
80-
TracingUtils.putAnnotation("Test", "New");
81-
String output = String.format("{ \"message\": \"hello world\", \"location\": \"%s\" }", pageContents);
82-
83-
TracingUtils.withSubsegment("loggingResponse", subsegment -> {
84-
String sampled = "log something out";
85-
log.info(sampled);
86-
log.info(output);
87-
});
66+
String output = String.format("{ \"message\": \"hello world\", \"location\": \"%s\" }", "Test");
8867

89-
log.info("After output");
9068
return response
9169
.withStatusCode(200)
9270
.withBody(output);
93-
} catch (RuntimeException | IOException e) {
71+
} catch (RuntimeException e) {
9472
return response
9573
.withBody("{}")
9674
.withStatusCode(500);
9775
}
9876
}
9977

100-
@Tracing
101-
private void log() {
102-
log.info("inside threaded logging for function");
103-
}
104-
105-
@Tracing(namespace = "getPageContents", captureMode = CaptureMode.DISABLED)
106-
private String getPageContents(String address) throws IOException {
107-
URL url = new URL(address);
108-
putMetadata("getPageContents", address);
109-
try (BufferedReader br = new BufferedReader(new InputStreamReader(url.openStream()))) {
110-
return br.lines().collect(Collectors.joining(System.lineSeparator()));
111-
}
112-
}
11378
}

examples/powertools-examples-core-utilities/sam/src/main/resources/log4j2.xml

Lines changed: 6 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -4,13 +4,13 @@
44
<Console name="JsonAppender" target="SYSTEM_OUT">
55
<JsonTemplateLayout eventTemplateUri="classpath:LambdaJsonLayout.json" />
66
</Console>
7+
<BufferingAppender name="BufferedAppender" bufferAtVerbosity="DEBUG">
8+
<AppenderRef ref="JsonAppender" />
9+
</BufferingAppender>
710
</Appenders>
811
<Loggers>
9-
<Logger name="JsonLogger" level="INFO" additivity="false">
10-
<AppenderRef ref="JsonAppender"/>
11-
</Logger>
12-
<Root level="info">
13-
<AppenderRef ref="JsonAppender"/>
12+
<Root level="debug">
13+
<AppenderRef ref="BufferedAppender" />
1414
</Root>
1515
</Loggers>
16-
</Configuration>
16+
</Configuration>

examples/powertools-examples-core-utilities/sam/template.yaml

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -13,9 +13,9 @@ Globals:
1313
Environment:
1414
Variables:
1515
# Powertools for AWS Lambda (Java) env vars: https://docs.powertools.aws.dev/lambda/java/#environment-variables
16-
POWERTOOLS_LOG_LEVEL: INFO
17-
POWERTOOLS_LOGGER_SAMPLE_RATE: 0.1
18-
POWERTOOLS_LOGGER_LOG_EVENT: true
16+
POWERTOOLS_LOG_LEVEL: DEBUG
17+
# POWERTOOLS_LOGGER_SAMPLE_RATE: 0.1
18+
POWERTOOLS_LOGGER_LOG_EVENT: false
1919
POWERTOOLS_METRICS_NAMESPACE: Coreutilities
2020

2121
Resources:
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,178 @@
1+
/*
2+
* Copyright 2023 Amazon.com, Inc. or its affiliates.
3+
* Licensed under the Apache License, Version 2.0 (the
4+
* "License"); you may not use this file except in compliance
5+
* with the License. You may obtain a copy of the License at
6+
* http://www.apache.org/licenses/LICENSE-2.0
7+
* Unless required by applicable law or agreed to in writing, software
8+
* distributed under the License is distributed on an "AS IS" BASIS,
9+
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
10+
* See the License for the specific language governing permissions and
11+
* limitations under the License.
12+
*
13+
*/
14+
15+
package software.amazon.lambda.powertools.logging.log4j;
16+
17+
import java.io.Serializable;
18+
import java.util.ArrayDeque;
19+
import java.util.Deque;
20+
import java.util.Map;
21+
import java.util.concurrent.ConcurrentHashMap;
22+
23+
import org.apache.logging.log4j.Level;
24+
import org.apache.logging.log4j.core.Appender;
25+
import org.apache.logging.log4j.core.Core;
26+
import org.apache.logging.log4j.core.Filter;
27+
import org.apache.logging.log4j.core.Layout;
28+
import org.apache.logging.log4j.core.LogEvent;
29+
import org.apache.logging.log4j.core.appender.AbstractAppender;
30+
import org.apache.logging.log4j.core.config.AppenderRef;
31+
import org.apache.logging.log4j.core.config.Configuration;
32+
import org.apache.logging.log4j.core.config.plugins.Plugin;
33+
import org.apache.logging.log4j.core.config.plugins.PluginAttribute;
34+
import org.apache.logging.log4j.core.config.plugins.PluginConfiguration;
35+
import org.apache.logging.log4j.core.config.plugins.PluginElement;
36+
import org.apache.logging.log4j.core.config.plugins.PluginFactory;
37+
import org.apache.logging.log4j.core.impl.Log4jLogEvent;
38+
39+
import software.amazon.lambda.powertools.common.internal.LambdaHandlerProcessor;
40+
41+
/**
42+
* A minimalistic Log4j2 appender that buffers log events based on trace ID
43+
* and flushes them when error logs are encountered or manually triggered.
44+
*/
45+
@Plugin(name = "BufferingAppender", category = Core.CATEGORY_NAME, elementType = Appender.ELEMENT_TYPE)
46+
public class BufferingAppender extends AbstractAppender {
47+
48+
private final AppenderRef[] appenderRefs;
49+
private final Configuration configuration;
50+
private final Level bufferAtVerbosity;
51+
private final int maxBytes;
52+
private final boolean flushOnErrorLog;
53+
private final Map<String, Deque<LogEvent>> bufferCache = new ConcurrentHashMap<>();
54+
private final ThreadLocal<Boolean> bufferOverflowWarned = new ThreadLocal<>();
55+
56+
protected BufferingAppender(String name, Filter filter, Layout<? extends Serializable> layout,
57+
AppenderRef[] appenderRefs, Configuration configuration, Level bufferAtVerbosity, int maxBytes,
58+
boolean flushOnErrorLog) {
59+
super(name, filter, layout, false, null);
60+
this.appenderRefs = appenderRefs;
61+
this.configuration = configuration;
62+
this.bufferAtVerbosity = bufferAtVerbosity;
63+
this.maxBytes = maxBytes;
64+
this.flushOnErrorLog = flushOnErrorLog;
65+
}
66+
67+
@Override
68+
public void append(LogEvent event) {
69+
if (appenderRefs == null || appenderRefs.length == 0) {
70+
return;
71+
}
72+
LambdaHandlerProcessor.getXrayTraceId().ifPresentOrElse(
73+
traceId -> {
74+
// Check if we should buffer this log level
75+
if (shouldBuffer(event.getLevel())) {
76+
bufferEvent(traceId, event);
77+
} else {
78+
callAppenders(event);
79+
}
80+
81+
// Flush buffer on error logs if configured
82+
if (flushOnErrorLog && event.getLevel().isMoreSpecificThan(Level.WARN)) {
83+
flushBuffer(traceId);
84+
}
85+
},
86+
() -> callAppenders(event) // No trace ID (INIT phase), log directly
87+
);
88+
}
89+
90+
private void callAppenders(LogEvent event) {
91+
for (AppenderRef ref : appenderRefs) {
92+
Appender appender = configuration.getAppender(ref.getRef());
93+
if (appender != null) {
94+
appender.append(event);
95+
}
96+
}
97+
}
98+
99+
private boolean shouldBuffer(Level level) {
100+
return level.isLessSpecificThan(bufferAtVerbosity) || level.equals(bufferAtVerbosity);
101+
}
102+
103+
private void bufferEvent(String traceId, LogEvent event) {
104+
// Create immutable copy to prevent mutation
105+
LogEvent immutableEvent = Log4jLogEvent.createMemento(event);
106+
107+
// Check if single event is larger than buffer - discard if so
108+
int eventSize = immutableEvent.getMessage().getFormattedMessage().length();
109+
if (eventSize > maxBytes) {
110+
if (Boolean.TRUE != bufferOverflowWarned.get()) {
111+
bufferOverflowWarned.set(true);
112+
}
113+
return;
114+
}
115+
116+
bufferCache.computeIfAbsent(traceId, k -> new ArrayDeque<>()).add(immutableEvent);
117+
118+
// Simple size check - remove oldest if over limit
119+
Deque<LogEvent> buffer = bufferCache.get(traceId);
120+
while (getBufferSize(buffer) > maxBytes && !buffer.isEmpty()) {
121+
if (Boolean.TRUE != bufferOverflowWarned.get()) {
122+
bufferOverflowWarned.set(true);
123+
}
124+
buffer.removeFirst();
125+
}
126+
}
127+
128+
private int getBufferSize(Deque<LogEvent> buffer) {
129+
return buffer.stream()
130+
.mapToInt(event -> event.getMessage().getFormattedMessage().length())
131+
.sum();
132+
}
133+
134+
public void clearBuffer() {
135+
LambdaHandlerProcessor.getXrayTraceId().ifPresent(bufferCache::remove);
136+
}
137+
138+
public void flushBuffer() {
139+
LambdaHandlerProcessor.getXrayTraceId().ifPresent(this::flushBuffer);
140+
}
141+
142+
private void flushBuffer(String traceId) {
143+
Deque<LogEvent> buffer = bufferCache.remove(traceId);
144+
if (buffer != null) {
145+
// Emit buffer overflow warning if it occurred
146+
if (Boolean.TRUE == bufferOverflowWarned.get()) {
147+
LOGGER.warn("Buffer size exceeded for trace ID: {}. Some log events were discarded.", traceId);
148+
bufferOverflowWarned.remove();
149+
}
150+
buffer.forEach(this::callAppenders);
151+
}
152+
}
153+
154+
@PluginFactory
155+
public static BufferingAppender createAppender(
156+
@PluginAttribute("name") String name,
157+
@PluginElement("Filter") Filter filter,
158+
@PluginElement("Layout") Layout<? extends Serializable> layout,
159+
@PluginElement("AppenderRef") AppenderRef[] appenderRefs,
160+
@PluginConfiguration Configuration configuration,
161+
@PluginAttribute(value = "bufferAtVerbosity", defaultString = "DEBUG") String bufferAtVerbosity,
162+
@PluginAttribute(value = "maxBytes", defaultInt = 20480) int maxBytes,
163+
@PluginAttribute(value = "flushOnErrorLog", defaultBoolean = true) boolean flushOnErrorLog) {
164+
165+
if (name == null) {
166+
LOGGER.error("No name provided for BufferingAppender");
167+
return null;
168+
}
169+
170+
Level level = Level.getLevel(bufferAtVerbosity);
171+
if (level == null) {
172+
level = Level.DEBUG;
173+
}
174+
175+
return new BufferingAppender(name, filter, layout, appenderRefs, configuration, level, maxBytes,
176+
flushOnErrorLog);
177+
}
178+
}
Lines changed: 33 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -12,19 +12,23 @@
1212
*
1313
*/
1414

15-
package software.amazon.lambda.powertools.logging.log4.internal;
15+
package software.amazon.lambda.powertools.logging.log4j.internal;
1616

1717
import org.apache.logging.log4j.Level;
1818
import org.apache.logging.log4j.LogManager;
1919
import org.apache.logging.log4j.core.LoggerContext;
2020
import org.apache.logging.log4j.core.config.Configurator;
2121
import org.slf4j.Logger;
22+
23+
import software.amazon.lambda.powertools.logging.internal.BufferManager;
2224
import software.amazon.lambda.powertools.logging.internal.LoggingManager;
25+
import software.amazon.lambda.powertools.logging.log4j.BufferingAppender;
2326

2427
/**
25-
* LoggingManager for Log4j2 (see {@link LoggingManager}).
28+
* LoggingManager for Log4j2 that provides log level management and buffer operations.
29+
* Implements both {@link LoggingManager} and {@link BufferManager} interfaces.
2630
*/
27-
public class Log4jLoggingManager implements LoggingManager {
31+
public class Log4jLoggingManager implements LoggingManager, BufferManager {
2832

2933
/**
3034
* @inheritDoc
@@ -45,4 +49,30 @@ public org.slf4j.event.Level getLogLevel(Logger logger) {
4549
LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
4650
return org.slf4j.event.Level.valueOf(ctx.getLogger(logger.getName()).getLevel().toString());
4751
}
52+
53+
/**
54+
* @inheritDoc
55+
*/
56+
@Override
57+
public void flushBuffer() {
58+
LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
59+
BufferingAppender bufferingAppender = (BufferingAppender) ctx.getConfiguration()
60+
.getAppender("BufferedAppender");
61+
if (bufferingAppender != null) {
62+
bufferingAppender.flushBuffer();
63+
}
64+
}
65+
66+
/**
67+
* @inheritDoc
68+
*/
69+
@Override
70+
public void clearBuffer() {
71+
LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
72+
BufferingAppender bufferingAppender = (BufferingAppender) ctx.getConfiguration()
73+
.getAppender("BufferedAppender");
74+
if (bufferingAppender != null) {
75+
bufferingAppender.clearBuffer();
76+
}
77+
}
4878
}
Original file line numberDiff line numberDiff line change
@@ -1 +1 @@
1-
software.amazon.lambda.powertools.logging.log4.internal.Log4jLoggingManager
1+
software.amazon.lambda.powertools.logging.log4j.internal.Log4jLoggingManager

0 commit comments

Comments
 (0)