Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: Add support for POWERTOOLS_LOGGER_LOG_EVENT #1510

Merged
Merged
Show file tree
Hide file tree
Changes from 4 commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
30 changes: 16 additions & 14 deletions docs/core/logging.md
Original file line number Diff line number Diff line change
Expand Up @@ -200,27 +200,29 @@ You can also explicitly set a service name via **`POWERTOOLS_SERVICE_NAME`** env

Your logs will always include the following keys to your structured logging:

Key | Type | Example | Description
------------------------------------------------- | ------------------------------------------------- | --------------------------------------------------------------------------------- | -------------------------------------------------
**timestamp** | String | "2020-05-24 18:17:33,774" | Timestamp of actual log statement
**level** | String | "INFO" | Logging level
**coldStart** | Boolean | true| ColdStart value.
**service** | String | "payment" | Service name defined. "service_undefined" will be used if unknown
**samplingRate** | int | 0.1 | Debug logging sampling rate in percentage e.g. 10% in this case
**message** | String | "Collecting payment" | Log statement value. Unserializable JSON values will be casted to string
**functionName**| String | "example-powertools-HelloWorldFunction-1P1Z6B39FLU73"
**functionVersion**| String | "12"
**functionMemorySize**| String | "128"
**functionArn**| String | "arn:aws:lambda:eu-west-1:012345678910:function:example-powertools-HelloWorldFunction-1P1Z6B39FLU73"
**xray_trace_id**| String | "1-5759e988-bd862e3fe1be46a994272793" | X-Ray Trace ID when Lambda function has enabled Tracing
**function_request_id**| String | "899856cb-83d1-40d7-8611-9e78f15f32f4"" | AWS Request ID from lambda context
| Key | Type | Example | Description |
|-------------------------|---------|------------------------------------------------------------------------------------------------------|--------------------------------------------------------------------------|
| **timestamp** | String | "2020-05-24 18:17:33,774" | Timestamp of actual log statement |
| **level** | String | "INFO" | Logging level |
| **coldStart** | Boolean | true | ColdStart value. |
| **service** | String | "payment" | Service name defined. "service_undefined" will be used if unknown |
| **samplingRate** | int | 0.1 | Debug logging sampling rate in percentage e.g. 10% in this case |
| **message** | String | "Collecting payment" | Log statement value. Unserializable JSON values will be casted to string |
| **functionName** | String | "example-powertools-HelloWorldFunction-1P1Z6B39FLU73" | |
| **functionVersion** | String | "12" | |
| **functionMemorySize** | String | "128" | |
| **functionArn** | String | "arn:aws:lambda:eu-west-1:012345678910:function:example-powertools-HelloWorldFunction-1P1Z6B39FLU73" | |
| **xray_trace_id** | String | "1-5759e988-bd862e3fe1be46a994272793" | X-Ray Trace ID when Lambda function has enabled Tracing |
| **function_request_id** | String | "899856cb-83d1-40d7-8611-9e78f15f32f4"" | AWS Request ID from lambda context |
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

sorry to say that but can we avoid this reformatting? will be a mess with v2...

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No big deal


## Capturing context Lambda info

You can enrich your structured logs with key Lambda context information via `logEvent` annotation parameter.
You can also explicitly log any incoming event using `logEvent` param. Refer [Override default object mapper](#override-default-object-mapper)
to customise what is logged.

Note that the `logEvent` will work only if `POWERTOOLS_LOGGER_SAMPLE_RATE` environment variable is set to `"true"`
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

is it the python behaviour ?

I think it is either one or the other to have the event logged, not both

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We should follow python. It's either one or the other, objective is to simplify job, users choose either programatic way or with env var, we don't want to complexify and require both. More over, if we require both, it becomes a breaking change and should go in v2.


!!! warning
Log event is disabled by default to prevent sensitive info being logged.

Expand Down
18 changes: 10 additions & 8 deletions docs/index.md
Original file line number Diff line number Diff line change
Expand Up @@ -279,11 +279,13 @@ Depending on your version of Java (either Java 1.8 or 11+), the configuration sl
!!! info
**Explicit parameters take precedence over environment variables.**

| Environment variable | Description | Utility |
| ------------------------------------------------- | --------------------------------------------------------------------------------- | --------------------------------------------------------------------------------- |
| **POWERTOOLS_SERVICE_NAME** | Sets service name used for tracing namespace, metrics dimension and structured logging | All |
| **POWERTOOLS_METRICS_NAMESPACE** | Sets namespace used for metrics | [Metrics](./core/metrics) |
| **POWERTOOLS_LOGGER_SAMPLE_RATE** | Debug log sampling | [Logging](./core/logging) |
| **POWERTOOLS_LOG_LEVEL** | Sets logging level | [Logging](./core/logging) |
| **POWERTOOLS_TRACER_CAPTURE_RESPONSE** | Enables/Disables tracing mode to capture method response | [Tracing](./core/tracing) |
| **POWERTOOLS_TRACER_CAPTURE_ERROR** | Enables/Disables tracing mode to capture method error | [Tracing](./core/tracing) |
| Environment variable | Description | Utility |
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

same here, can you avoid reformat, just add the new env var

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'll do a proper formatting in v2

|----------------------------------------|----------------------------------------------------------------------------------------|---------------------------|
| **POWERTOOLS_SERVICE_NAME** | Sets service name used for tracing namespace, metrics dimension and structured logging | All |
| **POWERTOOLS_METRICS_NAMESPACE** | Sets namespace used for metrics | [Metrics](./core/metrics) |
| **POWERTOOLS_LOGGER_SAMPLE_RATE** | Debug log sampling | [Logging](./core/logging) |
| **POWERTOOLS_LOG_LEVEL** | Sets logging level | [Logging](./core/logging) |
| **POWERTOOLS_LOGGER_LOG_EVENT** | Enables/Disables whether to log the incoming event when using the aspect | [Logging](./core/logging) |
| **POWERTOOLS_TRACER_CAPTURE_RESPONSE** | Enables/Disables tracing mode to capture method response | [Tracing](./core/tracing) |
| **POWERTOOLS_TRACER_CAPTURE_ERROR** | Enables/Disables tracing mode to capture method error | [Tracing](./core/tracing) |

Original file line number Diff line number Diff line change
@@ -0,0 +1,21 @@
/*
* Copyright 2023 Amazon.com, Inc. or its affiliates.
* Licensed under the Apache License, Version 2.0 (the
* "License"); you may not use this file except in compliance
* with the License. You may obtain a copy of the License at
* http://www.apache.org/licenses/LICENSE-2.0
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*
*/

package software.amazon.lambda.powertools.core.internal;

public final class EnvironmentVariables {
public static class LOGGER {
public final static String LOG_EVENT = "POWERTOOLS_LOGGER_LOG_EVENT";
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we already have other files containing environment variables, do not introduce a new one please

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

maybe that's something we should clean up in v2 by the way.

}
}
Original file line number Diff line number Diff line change
Expand Up @@ -47,6 +47,13 @@ public static boolean isHandlerMethod(final ProceedingJoinPoint pjp) {
return placedOnRequestHandler(pjp) || placedOnStreamHandler(pjp);
}

/**
jeromevdl marked this conversation as resolved.
Show resolved Hide resolved
* The class needs to implement RequestHandler interface
* The function needs to have exactly two arguments
* The second argument needs to be of type com.amazonaws.services.lambda.runtime.Context
* @param pjp
* @return
*/
public static boolean placedOnRequestHandler(final ProceedingJoinPoint pjp) {
return RequestHandler.class.isAssignableFrom(pjp.getSignature().getDeclaringType())
&& pjp.getArgs().length == 2
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -54,6 +54,7 @@
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.DeclarePrecedence;
import org.aspectj.lang.annotation.Pointcut;
import software.amazon.lambda.powertools.core.internal.EnvironmentVariables;
import software.amazon.lambda.powertools.logging.Logging;
import software.amazon.lambda.powertools.logging.LoggingUtils;

Expand All @@ -65,6 +66,7 @@ public final class LambdaLoggingAspect {

private static final String LOG_LEVEL = System.getenv("POWERTOOLS_LOG_LEVEL");
private static final String SAMPLING_RATE = System.getenv("POWERTOOLS_LOGGER_SAMPLE_RATE");
private static Boolean LOG_EVENT;

private static Level LEVEL_AT_INITIALISATION;

Expand All @@ -74,6 +76,12 @@ public final class LambdaLoggingAspect {
}

LEVEL_AT_INITIALISATION = LOG.getLevel();

if (System.getenv(EnvironmentVariables.LOGGER.LOG_EVENT) != null) {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

please, remain consistent with the other environment variables line 67/68, we'll create a proper file in v2...

LOG_EVENT = Boolean.parseBoolean(System.getenv(EnvironmentVariables.LOGGER.LOG_EVENT));
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

twice getenv, can you use a variable?

} else {
LOG_EVENT = false;
}
}

private static void resetLogLevels(Level logLevel) {
Expand Down Expand Up @@ -104,7 +112,9 @@ public Object around(ProceedingJoinPoint pjp,

getXrayTraceId().ifPresent(xRayTraceId -> appendKey("xray_trace_id", xRayTraceId));

if (logging.logEvent()) {
// Make sure that the environment variable was enabled explicitly
// And that the handler was annotated with @Logging(logEvent = true)
if (LOG_EVENT && logging.logEvent()) {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
if (LOG_EVENT && logging.logEvent()) {
if (LOG_EVENT || logging.logEvent()) {

proceedArgs = logEvent(pjp);
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -14,19 +14,6 @@

package software.amazon.lambda.powertools.logging.internal;

import static java.util.Collections.emptyMap;
import static java.util.Collections.singletonList;
import static java.util.stream.Collectors.joining;
import static org.apache.commons.lang3.reflect.FieldUtils.writeStaticField;
import static org.assertj.core.api.Assertions.assertThat;
import static org.assertj.core.api.Assertions.fail;
import static org.mockito.Mockito.mockStatic;
import static org.mockito.Mockito.when;
import static org.mockito.MockitoAnnotations.openMocks;
import static org.skyscreamer.jsonassert.JSONAssert.assertEquals;
import static software.amazon.lambda.powertools.core.internal.SystemWrapper.getProperty;
import static software.amazon.lambda.powertools.core.internal.SystemWrapper.getenv;

import com.amazonaws.services.lambda.runtime.Context;
import com.amazonaws.services.lambda.runtime.RequestHandler;
import com.amazonaws.services.lambda.runtime.RequestStreamHandler;
Expand All @@ -37,21 +24,6 @@
import com.amazonaws.services.lambda.runtime.tests.annotations.Event;
import com.fasterxml.jackson.core.JsonProcessingException;
import com.fasterxml.jackson.databind.ObjectMapper;
import java.io.BufferedReader;
import java.io.ByteArrayInputStream;
import java.io.ByteArrayOutputStream;
import java.io.IOException;
import java.io.InputStreamReader;
import java.lang.reflect.InvocationTargetException;
import java.lang.reflect.Method;
import java.nio.channels.FileChannel;
import java.nio.charset.StandardCharsets;
import java.nio.file.Files;
import java.nio.file.Paths;
import java.nio.file.StandardOpenOption;
import java.util.List;
import java.util.Map;
import java.util.stream.Collectors;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.ThreadContext;
import org.json.JSONException;
Expand All @@ -62,18 +34,32 @@
import org.mockito.MockedStatic;
import software.amazon.lambda.powertools.core.internal.LambdaHandlerProcessor;
import software.amazon.lambda.powertools.core.internal.SystemWrapper;
import software.amazon.lambda.powertools.logging.handlers.PowerLogToolApiGatewayHttpApiCorrelationId;
import software.amazon.lambda.powertools.logging.handlers.PowerLogToolApiGatewayRestApiCorrelationId;
import software.amazon.lambda.powertools.logging.handlers.PowerLogToolEnabled;
import software.amazon.lambda.powertools.logging.handlers.PowerLogToolEnabledForStream;
import software.amazon.lambda.powertools.logging.handlers.PowerToolDisabled;
import software.amazon.lambda.powertools.logging.handlers.PowerToolDisabledForStream;
import software.amazon.lambda.powertools.logging.handlers.PowerToolLogEventEnabled;
import software.amazon.lambda.powertools.logging.handlers.PowerToolLogEventEnabledForStream;
import software.amazon.lambda.powertools.logging.handlers.PowerToolLogEventEnabledWithCustomMapper;
import software.amazon.lambda.powertools.logging.handlers.PowertoolsLogAlbCorrelationId;
import software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEnabledWithClearState;
import software.amazon.lambda.powertools.logging.handlers.PowertoolsLogEventBridgeCorrelationId;
import software.amazon.lambda.powertools.logging.handlers.*;

import java.io.*;
import java.lang.reflect.InvocationTargetException;
import java.lang.reflect.Method;
import java.nio.channels.FileChannel;
import java.nio.charset.StandardCharsets;
import java.nio.file.Files;
import java.nio.file.Paths;
import java.nio.file.StandardOpenOption;
import java.util.List;
import java.util.Map;
import java.util.stream.Collectors;

import static java.util.Collections.emptyMap;
import static java.util.Collections.singletonList;
import static java.util.stream.Collectors.joining;
import static org.apache.commons.lang3.reflect.FieldUtils.writeStaticField;
import static org.assertj.core.api.Assertions.assertThat;
import static org.assertj.core.api.Assertions.fail;
import static org.mockito.Mockito.mockStatic;
import static org.mockito.Mockito.when;
import static org.mockito.MockitoAnnotations.openMocks;
import static org.skyscreamer.jsonassert.JSONAssert.assertEquals;
import static software.amazon.lambda.powertools.core.internal.SystemWrapper.getProperty;
import static software.amazon.lambda.powertools.core.internal.SystemWrapper.getenv;

class LambdaLoggingAspectTest {

Expand All @@ -89,6 +75,7 @@ void setUp() throws IllegalAccessException, IOException, NoSuchMethodException,
openMocks(this);
ThreadContext.clearAll();
writeStaticField(LambdaHandlerProcessor.class, "IS_COLD_START", null, true);
writeStaticField(LambdaLoggingAspect.class, "LOG_EVENT", Boolean.TRUE, true);
setupContext();
requestHandler = new PowerLogToolEnabled();
requestStreamHandler = new PowerLogToolEnabledForStream();
Expand Down Expand Up @@ -195,6 +182,23 @@ void shouldLogEventForHandler() throws IOException, JSONException {
assertEquals(expectEvent, event, false);
}

/**
* If POWERTOOLS_LOGGER_LOG_EVENT was set to false, the handler should log anything, despite @Logging(logEvent=true)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

no, see my other comment

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

python is the ref, not typescript

* @throws IOException
*/
@Test
void shouldNotLogEventForHandlerWhenEnvVariableSetToFalse() throws IOException, IllegalAccessException {
writeStaticField(LambdaLoggingAspect.class, "LOG_EVENT", Boolean.FALSE, true);

requestHandler = new PowerToolLogEventEnabled();
S3EventNotification s3EventNotification = s3EventNotification();

requestHandler.handleRequest(s3EventNotification, context);

String s = Files.lines(Paths.get("target/logfile.json")).collect(joining());
assertThat(s).isEmpty();
}

@Test
void shouldLogEventForHandlerWithOverriddenObjectMapper() throws IOException, JSONException {
RequestHandler<S3EventNotification, Object> handler = new PowerToolLogEventEnabledWithCustomMapper();
Expand Down
9 changes: 9 additions & 0 deletions powertools-test-suite/pom.xml
Original file line number Diff line number Diff line change
Expand Up @@ -119,6 +119,15 @@

<build>
<plugins>
<plugin>
<groupId>org.apache.maven.plugins</groupId>
<artifactId>maven-surefire-plugin</artifactId>
<configuration>
<environmentVariables>
<POWERTOOLS_LOGGER_LOG_EVENT>true</POWERTOOLS_LOGGER_LOG_EVENT>
</environmentVariables>
</configuration>
</plugin>
<plugin>
<groupId>dev.aspectj</groupId>
<artifactId>aspectj-maven-plugin</artifactId>
Expand Down