8

I'm running a lamba on AWS, and using slf4j for logging

Part of the project requirements is that the log level can be set at runtime, using an environment variable, but I'm not sure if that's possible

I'm using the following code, but changing the environment variable "LOG_LEVEL" in the UI to "DEBUG" has no effect to what is added to the CloudWatch logs. Is this possible?

import org.apache.log4j.Level;
import org.apache.log4j.LogManager;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class MyLambdaHandler implements RequestHandler<Integer, String> {

    private static final Logger LOGGER = LoggerFactory.getLogger(MyLambdaHandler.class);

    static {
        org.apache.log4j.Logger rootLogger = LogManager.getRootLogger();
        String logLevel = (System.getenv("LOG_LEVEL") != null) ? System.getenv("LOG_LEVEL") : "INFO";
        rootLogger.setLevel(Level.toLevel(logLevel));
    }

    public String myHandler(int myCount, Context context) {

        LOGGER.debug("Entering myHandler lambda handler";
        LOGGER.info("Handling myCount {}", myCount);
        int returnValue = myCount * 2;
        LOGGER.debug("MyHandler return value {}", returnValue);
        return returnValue;

    }

}
ParisFA
  • 73
  • 8
Joseph McCarthy
  • 771
  • 1
  • 15
  • 27

2 Answers2

3

Yes it's possible! You need to take care of two things:

  • One, update your lambda environment variable
  • Two, ensure that log4j will pick up the update

For the first problem, all you need to do is pass a lambda environment variable with name JAVA_TOOL_OPTIONS and value "-DLOG_LEVEL=DEBUG".

For the second point, you can add this to your Java project src/main/resources/log4j.properties with content something like

log4j.rootCategory=${LOG_LEVEL}, LAMBDA
LOG_LEVEL_PATTERN=%5p
LOG_PATTERN=[%d{yyyy-MM-dd HH:mm:ss.SSS}] boot%X{context} ${LOG_LEVEL_PATTERN} [%t] - %c{1}: %m%n
log4j.appender.LAMBDA=com.amazonaws.services.lambda.runtime.log4j.LambdaAppender
log4j.appender.LAMBDA.layout=org.apache.log4j.PatternLayout
log4j.appender.LAMBDA.layout.conversionPattern=${LOG_PATTERN}

And that's it!

If everything goes well you should soon see in your logs a line reading something like

Picked up JAVA_TOOL_OPTIONS: -DLOG_LEVEL=DEBUG

and hopefully start seeing some debug statements.

Notice how LOG_LEVEL is embedded in the value of the lambda variable as opposed to being the variable name. This is a useful indirect way to feed JVM arguments down a lambda which you can then use as system properties. Kudos to https://zenidas.wordpress.com/recipes/system-properties-for-a-java-lambda-function/

tuomastik
  • 3,586
  • 5
  • 28
  • 41
ParisFA
  • 73
  • 8
3

I was able to resolve this by using the amazon version of log4j2, and making a change to the log4j2.xml configuration file Add these dependencies to maven

<dependency>
    <groupId>com.amazonaws</groupId>
    <artifactId>aws-lambda-java-log4j2</artifactId>
    <version>1.1.0</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-core</artifactId>
    <version>2.11.2</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-api</artifactId>
    <version>2.11.2</version>
</dependency>

use the environment variable in the level of the logger in the configuration

<?xml version="1.0" encoding="UTF-8"?>
<Configuration
    packages="com.amazonaws.services.lambda.runtime.log4j2">
    <Appenders>
        <Lambda name="Lambda">
            <PatternLayout>
                <pattern>%d{yyyy-MM-dd HH:mm:ss} %X{AWSRequestId} %-5p %c{1}:%L - %m%n</pattern>
            </PatternLayout>
        </Lambda>
    </Appenders>
    <Loggers>
        <Root level="${env:LOG_LEVEL}">
            <AppenderRef ref="Lambda" />
        </Root>
    </Loggers>
</Configuration>

finally, use the log4j2 logger in the lambda itself

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class MyLambdaHandler implements RequestHandler<Void, Void> {

    private static final Logger LOGGER = LogManager.getLogger(MyLambdaHandler .class);

    public Void handleRequest(Void myVoid, Context context) {

        LOGGER.error("Log info enabled: {}", LOGGER.isInfoEnabled());
        LOGGER.info("Info messge");
        LOGGER.error("Log error enabled: {}",  LOGGER.isErrorEnabled());
        LOGGER.error("Error Message");
        LOGGER.error("Log trace enabled: {}",  LOGGER.isTraceEnabled());
        LOGGER.trace("trace message");
        LOGGER.error("Log warning enabled: {}",  LOGGER.isWarnEnabled());
        LOGGER.warn("warn message");
        LOGGER.error("Log debug enabled: {}",  LOGGER.isDebugEnabled());
        LOGGER.debug("debug message");
        return null;

    }

}    

then set the LOG_LEVEL environment variable to the appropriate level to see the the relevant entries in the logs

Joseph McCarthy
  • 771
  • 1
  • 15
  • 27
  • Were you using the maven shade plugin with this Lambda and got it working with that too? – Darren Jul 10 '19 at 22:28
  • 1
    I've added the code to a github repo here: https://github.com/tetsujin1979/aws-log-level – Joseph McCarthy Jul 11 '19 at 10:44
  • @JosephMcCarthy I created a lambda from your git repo and set the env variable LOG_LEVEL to info but I still dont see any log message in log output, I just see the below(skipping start request and report request msg) %d [%thread] %-5level %logger - %msg%n%d [%thread] %-5level %logger - %msg%n%d [%thread] %-5level %logger - %msg%n%d [%thread] %-5level %logger - %msg%n%d [%thread] %-5level %logger - %msg%n%d [%thread] %-5level %logger - %msg%nEND RequestId: 4ecf66b5-480e-4068-a9c1-e32433e487d9 Am I missing anything ? – abhishekmahawar Jul 23 '19 at 11:46
  • The cloudwatch logs also says "ERROR StatusLogger Unrecognized format specifier [d]" and other similar messages – abhishekmahawar Jul 23 '19 at 12:00
  • Ok, I was able to resolve the issue by using the shade plugin config defined here : https://github.com/aws/aws-lambda-java-libs/tree/master/aws-lambda-java-log4j2 – abhishekmahawar Jul 23 '19 at 12:08