search

aws-powertools / powertools-lambda-java

Powertools is a developer toolkit to implement Serverless best practices and increase developer velocity.
https://docs.powertools.aws.dev/lambda/java/
MIT No Attribution
277 stars 83 forks source link

GraalVM Support #764

Open driverpt opened 2 years ago

driverpt commented 2 years ago

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 commented 2 years ago

Hi @driverpt

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

Thanks,

Mark

madeupname commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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:

https://github.com/madeupname/samkgg/commit/b404f554cee3a60ca4daa5bb5f7241c6bd0d4dbf

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

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 commented 1 year ago

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 commented 1 year ago

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

miracle-the-V commented 1 year ago

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 commented 1 year ago

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?

Frontrider commented 11 months ago

Until then have you considered using Lambda SnapStart?

We are already using graal, and it is significantly better than snapstart. It simply can not compete with a flat 5-10x increase in speed (compared to snapstart, can be 20x without it), and you can actually benchmark it properly as it is consistent. (the jvm slowly tries to speed up with each execution, but in this environment it just can't) I'd even go as far as to say that it IS the correct way to use jvm languages with lambda functions.

jeromevdl commented 11 months ago

Thanks @Frontrider for the feedback.

May I ask if you have a running example of a Java / GraalVM Lambda working with powertools (logging) that you could share or if you want to write one for our examples?

maschnetwork commented 3 days ago

I'll take a look into the GraalVM Support and can add a working example - probably next month.

Frontrider commented 3 days ago

I'll note that I ended up not using this. The actual lambda I was developing long term was in kotlin, and the tools for that language generally don't have issues on graalvm.

jeromevdl commented 3 days ago

No problem @Frontrider, maybe we can do something for the others. Also note that Powertools works with Kotlin (example)