Spark: Cold start occassionally throws NullPointer exception about aws-serverless-java-container

[sapessi]

Thanks @lskrajny - marking as a bug for now. I'll investigate and let you know next week.

[sapessi]

I could replicate this in travis CI but not in local. I suspect this is a race condition where the ignite method is not called consistently before the handle method is called. To get around this, I have moved the Spark filter initialization to the constructor too.

This seems to work in the travis CI build, the only place where I could replicate the issue - still not clear whether this is an issue with Spark 2.6.0 or something that is expected.

@lskrajny can you help me test by checking out 0.8-SNAPSHOT from the servlet-improvements branch?

[lskrajny]

tested it but unfortunately this doesn't still seem to work:

START RequestId: f9662496-bd7a-11e7-88c9-d3bd55287df8 Version: $LATEST
30 Oct 2017 14:02:34 INFO LambdaContainerHandler - Starting Lambda Container Handler
30 Oct 2017 14:02:35 INFO LambdaHandler - Registering path: /v1
30 Oct 2017 14:02:35 ERROR LambdaContainerHandler - Error while handling request
java.lang.NullPointerException
at com.amazonaws.serverless.proxy.spark.SparkLambdaContainerHandler.handleRequest(SparkLambdaContainerHandler.java:171)
at com.amazonaws.serverless.proxy.spark.SparkLambdaContainerHandler.handleRequest(SparkLambdaContainerHandler.java:65)
at com.amazonaws.serverless.proxy.internal.LambdaContainerHandler.proxy(LambdaContainerHandler.java:126)
at com.logindex.lambda.LambdaHandler.handleRequest(LambdaHandler.kt:37)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at lambdainternal.EventHandlerLoader$PojoMethodRequestHandler.handleRequest(EventHandlerLoader.java:259)
at lambdainternal.EventHandlerLoader$PojoHandlerAsStreamHandler.handleRequest(EventHandlerLoader.java:178)
at lambdainternal.EventHandlerLoader$2.call(EventHandlerLoader.java:888)
at lambdainternal.AWSLambda.startRuntime(AWSLambda.java:281)
at lambdainternal.AWSLambda.<clinit>(AWSLambda.java:64)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:348)
at lambdainternal.LambdaRTEntry.main(LambdaRTEntry.java:94)
30 Oct 2017 14:02:35 ERROR AwsProxyExceptionHandler - Called exception handler for:
java.lang.NullPointerException
at com.amazonaws.serverless.proxy.spark.SparkLambdaContainerHandler.handleRequest(SparkLambdaContainerHandler.java:171)
at com.amazonaws.serverless.proxy.spark.SparkLambdaContainerHandler.handleRequest(SparkLambdaContainerHandler.java:65)
at com.amazonaws.serverless.proxy.internal.LambdaContainerHandler.proxy(LambdaContainerHandler.java:126)
at com.logindex.lambda.LambdaHandler.handleRequest(LambdaHandler.kt:37)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at lambdainternal.EventHandlerLoader$PojoMethodRequestHandler.handleRequest(EventHandlerLoader.java:259)
at lambdainternal.EventHandlerLoader$PojoHandlerAsStreamHandler.handleRequest(EventHandlerLoader.java:178)
at lambdainternal.EventHandlerLoader$2.call(EventHandlerLoader.java:888)
at lambdainternal.AWSLambda.startRuntime(AWSLambda.java:281)
at lambdainternal.AWSLambda.<clinit>(AWSLambda.java:64)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:348)
at lambdainternal.LambdaRTEntry.main(LambdaRTEntry.java:94)
30 Oct 2017 14:02:35 INFO LambdaEmbeddedServer - Spark called configureWebSockets. However, web sockets are not supported
30 Oct 2017 14:02:35 INFO LambdaEmbeddedServer - Starting Spark server, ignoring port and host
30 Oct 2017 14:02:35 INFO LambdaEmbeddedServer - Called join method, nothing to do here since Lambda only runs a single event per container
END RequestId: f9662496-bd7a-11e7-88c9-d3bd55287df8
REPORT RequestId: f9662496-bd7a-11e7-88c9-d3bd55287df8	Duration: 875.76 ms	Billed Duration: 900 ms Memory Size: 512 MB	Max Memory Used: 57 MB	

[sapessi]

Thanks for testing @lskrajny - I'll try and do some more work to replicate it. I would expect it to happen with the unit tests that start applications but so far I haven't had any luck.

[sapessi]

Hey @lskrajny - I'm still struggling to replicate in local. However, Travis CI did fail the build with a similar issues, really seems to be a race condition. I have made a couple of small changes and since then the Travis build has worked correctly. Do you mind testing again version 0.8-SNAPSHOT from the servlet-improvements branch?

[lskrajny]

Hi @sapessi - tested recent build, and observed NPE now is indeed less frequent, but it still exists. So possibility of the race was reduced but not eliminated.

In the meantime found solution to the initial problem, after adding Spark.awaitInitialization() in the initialization code of the Lambda handler (not the container library) NPE on initialization went away.

So initialization code looks like this (based on PetStore example):

        handler = SparkLambdaContainerHandler.getAwsProxyHandler()
        defineResources()
        Spark.awaitInitialization()

So the solution is either to modify the spark example to block until spark is initialized or trying to incorporate the fix in the library.

Hope that helps

[sapessi]

Thanks @lskrajny - I was basing my implementation on the default Jetty embedded server and it doesn't look like they call that method. Regardless, sounds like the right thing to do. I will incorporate the call in the framework and commit the changes now. Thanks for putting so much time into this. I'll push out 0.8 ASAP

[lskrajny]

Cool, once done will test

[sapessi]

Change is committed to the servlet-improvements branch. All unit tests still pass.

[lskrajny]

Strange, it is still throwing NPE :/

Could it be it is executing Spark.awaitInitialization() before routes are defined?

Regression tested using Spark.awaitInitialization() outside of the library and it works

[sapessi]

Looks like you are right. may have to call the awaitInitialization() after the routes are included. I'll add it to the documentation and sample instead :(

[sapessi]

ok. Pushed the updates to the servlet-improvements branch. I simply updated the README to include the call to awaitInitialization() and also added it to the sample app. Testing the changes now and then I'll commit and merge.

[sapessi]

@lskrajny I'm closing this issue for now. If you run into the error again even with the awaitInitialization re-open it and I'll dig deeper.