GraalVM Support for Core Utilities (Logging, Metrics, Tracing)

[driverpt]

Is your feature request related to a problem? Please describe.
We want to make Lambdas faster by turning them into native code.

Describe the solution you'd like
Add reflect.json or similar to META-INF to make it Native compatible

Describe alternatives you've considered
N/A

Additional context
N/A

[msailes]

Hi @driverpt

Can you let us know what errors you're seeing?

Thanks,

Mark

[madeupname]

I'm not the OP, but I'm also struggling with this. Do you have an example that shows this working on GraalVM? Because just for log4j2, it does appear you need to add quite a bit to resource-config.json and reflect-config.json to get it to run without crashing.

I'm working on an example project specifically to showcase GraalVM/Lambda and my first step is to add logging. You can see the code here:

https://github.com/madeupname/samkgg/tree/3-add-logging

I've followed a couple examples of getting log4j2 and GraalVM working and it doesn't crash anymore, but still has errors around Log4j. The method does run, but no logging.

I'll add that if you run gradle test, it works fine:

{"timestamp":"2022-09-08T00:15:48.010-0700PDT","instant":{"epochSecond":1662621348,"nanoOfSecond":10314100},"thread":"Test worker","level":"INFO","loggerName":"helloworld.App","message":"Entered handleRequest.","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":1,"threadPriority":5,"samplingRate":"0.0"}

But local invoke or deployed to AWS, it fails:

$ sam local invoke HelloWorldFunction --event events/event.json
Invoking helloworld.App::handleRequest (provided.al2)
Skip pulling image and use local one: public.ecr.aws/sam/emulation-provided.al2:rapid-1.54.0-x86_64.

Mounting C:\Java\Source\Idea\samkgg\.aws-sam\build\HelloWorldFunction as /var/task:ro,delegated inside runtime container
START RequestId: f47d4885-35b9-48c5-9daa-2ef692f89f4a Version: $LATEST
2022-09-08 05:42:00,921 main ERROR Console contains an invalid element or attribute "JsonTemplateLayout"
2022-09-08 05:42:00,951 main ERROR Logger contains invalid attributes "additivity", "level", "name"
2022-09-08 05:42:00,951 main ERROR logger Logger has no parameter that matches element AppenderRef
2022-09-08 05:42:00,951 main ERROR Could not create plugin of type class org.apache.logging.log4j.core.config.LoggerConfig for element Logger: java.lang.NullPointerException java.lang.NullPointerException
        at org.apache.logging.log4j.core.config.LoggerConfig$Builder.build(LoggerConfig.java:224)
        at org.apache.logging.log4j.core.config.LoggerConfig$Builder.build(LoggerConfig.java:118)
        at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:124)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:1133)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:1058)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:1050)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:659)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:257)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:303)
        at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:621)
        at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:694)
        at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:711)
        at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:253)
        at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:155)
        at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:47)
        at org.apache.logging.log4j.LogManager.getContext(LogManager.java:196)
        at org.apache.logging.log4j.LogManager.getLogger(LogManager.java:599)
        at org.apache.logging.log4j.LogManager.getLogger(LogManager.java:585)
        at helloworld.App.<init>(App.kt:15)
        at java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:480)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.newInstance(EventHandlerLoader.java:409)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader$PojoMethodRequestHandler.fromMethod(EventHandlerLoader.java:246)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader$PojoMethodRequestHandler.makeRequestHandler(EventHandlerLoader.java:260)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.getTwoLengthHandler(EventHandlerLoader.java:664)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.getHandlerFromOverload(EventHandlerLoader.java:697)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.loadEventPojoHandler(EventHandlerLoader.java:811)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.loadEventHandler(EventHandlerLoader.java:613)
        at com.amazonaws.services.lambda.runtime.api.client.AWSLambda.findUserMethods(AWSLambda.java:122)
        at com.amazonaws.services.lambda.runtime.api.client.AWSLambda.startRuntime(AWSLambda.java:226)
        at com.amazonaws.services.lambda.runtime.api.client.AWSLambda.startRuntime(AWSLambda.java:193)
        at com.amazonaws.services.lambda.runtime.api.client.AWSLambda.main(AWSLambda.java:188)

2022-09-08 05:42:00,951 main ERROR Unable to invoke factory method in class org.apache.logging.log4j.core.config.LoggerConfig for element Logger: java.lang.IllegalStateException: No factory method found for class org.apache.logging.log4j.core.config.LoggerConfig java
.lang.IllegalStateException: No factory method found for class org.apache.logging.log4j.core.config.LoggerConfig
        at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.findFactoryMethod(PluginBuilder.java:260)
        at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:136)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:1133)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:1058)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:1050)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:659)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:257)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:303)
        at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:621)
        at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:694)
        at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:711)
        at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:253)
        at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:155)
        at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:47)
        at org.apache.logging.log4j.LogManager.getContext(LogManager.java:196)
        at org.apache.logging.log4j.LogManager.getLogger(LogManager.java:599)
        at org.apache.logging.log4j.LogManager.getLogger(LogManager.java:585)
        at helloworld.App.<init>(App.kt:15)
        at java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:480)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.newInstance(EventHandlerLoader.java:409)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader$PojoMethodRequestHandler.fromMethod(EventHandlerLoader.java:246)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader$PojoMethodRequestHandler.makeRequestHandler(EventHandlerLoader.java:260)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.getTwoLengthHandler(EventHandlerLoader.java:664)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.getHandlerFromOverload(EventHandlerLoader.java:697)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.loadEventPojoHandler(EventHandlerLoader.java:811)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.loadEventHandler(EventHandlerLoader.java:613)
        at com.amazonaws.services.lambda.runtime.api.client.AWSLambda.findUserMethods(AWSLambda.java:122)
        at com.amazonaws.services.lambda.runtime.api.client.AWSLambda.startRuntime(AWSLambda.java:226)
        at com.amazonaws.services.lambda.runtime.api.client.AWSLambda.startRuntime(AWSLambda.java:193)
        at com.amazonaws.services.lambda.runtime.api.client.AWSLambda.main(AWSLambda.java:188)

2022-09-08 05:42:00,952 main ERROR Root contains an invalid element or attribute "level"
2022-09-08 05:42:00,952 main ERROR root Root has no parameter that matches element AppenderRef
2022-09-08 05:42:00,952 main ERROR Could not create plugin of type class org.apache.logging.log4j.core.config.LoggerConfig$RootLogger for element Root: java.lang.NullPointerException java.lang.NullPointerException
        at java.util.Objects.requireNonNull(Objects.java:208)
        at java.util.Arrays$ArrayList.<init>(Arrays.java:4137)
        at java.util.Arrays.asList(Arrays.java:4122)
        at org.apache.logging.log4j.core.config.LoggerConfig.getLevelAndRefs(LoggerConfig.java:949)
        at org.apache.logging.log4j.core.config.LoggerConfig$RootLogger$Builder.build(LoggerConfig.java:892)
        at org.apache.logging.log4j.core.config.LoggerConfig$RootLogger$Builder.build(LoggerConfig.java:798)
        at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:124)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:1133)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:1058)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:1050)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:659)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:257)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:303)
        at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:621)
        at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:694)
        at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:711)
        at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:253)
        at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:155)
        at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:47)
        at org.apache.logging.log4j.LogManager.getContext(LogManager.java:196)
        at org.apache.logging.log4j.LogManager.getLogger(LogManager.java:599)
        at org.apache.logging.log4j.LogManager.getLogger(LogManager.java:585)
        at helloworld.App.<init>(App.kt:15)
        at java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:480)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.newInstance(EventHandlerLoader.java:409)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader$PojoMethodRequestHandler.fromMethod(EventHandlerLoader.java:246)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader$PojoMethodRequestHandler.makeRequestHandler(EventHandlerLoader.java:260)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.getTwoLengthHandler(EventHandlerLoader.java:664)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.getHandlerFromOverload(EventHandlerLoader.java:697)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.loadEventPojoHandler(EventHandlerLoader.java:811)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.loadEventHandler(EventHandlerLoader.java:613)
        at com.amazonaws.services.lambda.runtime.api.client.AWSLambda.findUserMethods(AWSLambda.java:122)
        at com.amazonaws.services.lambda.runtime.api.client.AWSLambda.startRuntime(AWSLambda.java:226)
        at com.amazonaws.services.lambda.runtime.api.client.AWSLambda.startRuntime(AWSLambda.java:193)
        at com.amazonaws.services.lambda.runtime.api.client.AWSLambda.main(AWSLambda.java:188)

2022-09-08 05:42:00,953 main ERROR Unable to invoke factory method in class org.apache.logging.log4j.core.config.LoggerConfig$RootLogger for element Root: java.lang.IllegalStateException: No factory method found for class org.apache.logging.log4j.core.config.LoggerCo
nfig$RootLogger java.lang.IllegalStateException: No factory method found for class org.apache.logging.log4j.core.config.LoggerConfig$RootLogger
        at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.findFactoryMethod(PluginBuilder.java:260)
        at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:136)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:1133)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:1058)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:1050)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:659)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:257)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:303)
        at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:621)
        at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:694)
        at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:711)
        at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:253)
        at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:155)
        at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:47)
        at org.apache.logging.log4j.LogManager.getContext(LogManager.java:196)
        at org.apache.logging.log4j.LogManager.getLogger(LogManager.java:599)
        at org.apache.logging.log4j.LogManager.getLogger(LogManager.java:585)
        at helloworld.App.<init>(App.kt:15)
        at java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:480)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.newInstance(EventHandlerLoader.java:409)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader$PojoMethodRequestHandler.fromMethod(EventHandlerLoader.java:246)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader$PojoMethodRequestHandler.makeRequestHandler(EventHandlerLoader.java:260)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.getTwoLengthHandler(EventHandlerLoader.java:664)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.getHandlerFromOverload(EventHandlerLoader.java:697)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.loadEventPojoHandler(EventHandlerLoader.java:811)
        at com.amazonaws.services.lambda.runtime.api.client.EventHandlerLoader.loadEventHandler(EventHandlerLoader.java:613)
        at com.amazonaws.services.lambda.runtime.api.client.AWSLambda.findUserMethods(AWSLambda.java:122)
        at com.amazonaws.services.lambda.runtime.api.client.AWSLambda.startRuntime(AWSLambda.java:226)
        at com.amazonaws.services.lambda.runtime.api.client.AWSLambda.startRuntime(AWSLambda.java:193)
        at com.amazonaws.services.lambda.runtime.api.client.AWSLambda.main(AWSLambda.java:188)

2022-09-08 05:42:00,953 main ERROR Null object returned for Logger in Loggers.
2022-09-08 05:42:00,953 main ERROR Null object returned for Root in Loggers.
{"statusCode":200,"headers":{"X-Custom-Header":"application/json","Content-Type":"application/json"},"body":"{ \"message\": \"hello world\", \"location\": \"The Sol System\" }","isBase64Encoded":false}END RequestId: f47d4885-35b9-48c5-9daa-2ef692f89f4a
REPORT RequestId: f47d4885-35b9-48c5-9daa-2ef692f89f4a  Init Duration: 0.13 ms  Duration: 1861.74 ms    Billed Duration: 1862 ms        Memory Size: 256 MB     Max Memory Used: 256 MB

[msailes]

We have someone looking at GraalVM support atm, could you include the config you have so far.

I think this is more likely a Log4J issue, but we'll add their config to our project in the meantime.

[madeupname]

That's great to hear, excited to see a working example. My project is directly based on the official SAM GraalVM template. By config, I assume you mean what I have in resource-config.json and reflect-config.json to get it running. The project I linked is very small, but you can all changes I made for Powertools in this commit:

madeupname/samkgg@b404f55

As in the commit message, some things that might help you:

• Followed example here: https://github.com/muellerc/graalvm-sandbox/tree/main/log4j2-sandbox/src/main/resources/META-INF/native-image/com.amazonaws.sample.cmr.sns-throughput-optimization/log4j2-sandbox
• From this thread: Cannot build native image for trivial app with SLF4J and Log4J2 oracle/graal#2008
• GraalVM docs on logging: https://www.graalvm.org/22.1/reference-manual/native-image/Logging/

You can see from link above that GraalVM officially supports java.util.logging, but it does appear people have gotten log4j2 to work. Looks like considerably more effort, though.

[madeupname]

After further investigation, I'm giving up on Powertools in GraalVM. It looks great, but is coupled to Log4j 2 and they have said it does not and will not support GraalVM (maybe in Log4j 3): https://issues.apache.org/jira/browse/LOG4J2-2604

If you switch to a Graal-safe logging framework, I'm happy to try again.

I ended up using SLF4J and JUL. GraalVM and Lambda is surprisingly tricky for logging and I've documented my findings here: https://philip.yurchuk.com/software/samkgg-lessons-learned/#logging

[jeromevdl]

@madeupname I'm currently working on it (#965). But will probably be in a v2 as it comes with breaking changes.

[miracle-the-V]

Backing this. Native image assembly currently fails with
Caused by: org.graalvm.compiler.java.BytecodeParser$BytecodeParserError: com.oracle.graal.pointsto.constraints.UnresolvedElementException: Discovered unresolved type during parsing: org.osgi.framework.FrameworkUtil. This error is reported at image build time because class org.apache.logging.log4j.core.config.plugins.util.ResolverUtil is registered for linking at image build time by command line
Lambdas written in Java don't stand a chance without GraalVM native image when it comes to performance, so this is, unfortunately, a deal-breaker atm.

[msailes]

Hi @miraclefoxx,

This is a Log4J class which is causing the problem. We are considering changing our logging approach in the next major version. Until then have you considered using Lambda SnapStart?