Spark: Cold start occassionally throws NullPointer exception #71

lskrajny · 2017-09-22T21:34:57Z

Following spark sample, occasionally getting:

START RequestId: 1a7fc844-9fdd-11e7-bdf6-7b809f4c7a77 Version: $LATEST
22 Sep 2017 21:29:26 INFO LambdaContainerHandler - Starting Lambda Container Handler
22 Sep 2017 21:29:26 INFO LambdaHandler - Registering path: /sea/v1
22 Sep 2017 21:29:26 INFO LambdaEmbeddedServer - Spark called configureWebSockets. However, web sockets are not supported
22 Sep 2017 21:29:26 INFO LambdaEmbeddedServer - Starting Spark server, ignoring port and host
22 Sep 2017 21:29:26 ERROR LambdaContainerHandler - Error while handling request
java.lang.NullPointerException
at com.amazonaws.serverless.proxy.spark.SparkLambdaContainerHandler.handleRequest(SparkLambdaContainerHandler.java:169)
at com.amazonaws.serverless.proxy.spark.SparkLambdaContainerHandler.handleRequest(SparkLambdaContainerHandler.java:61)
at com.amazonaws.serverless.proxy.internal.LambdaContainerHandler.proxy(LambdaContainerHandler.java:126)
at com.logindex.lambda.LambdaHandler.handleRequest(LambdaHandler.kt:35)
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)
22 Sep 2017 21:29:27 ERROR AwsProxyExceptionHandler - Called exception handler for:
java.lang.NullPointerException
at com.amazonaws.serverless.proxy.spark.SparkLambdaContainerHandler.handleRequest(SparkLambdaContainerHandler.java:169)
at com.amazonaws.serverless.proxy.spark.SparkLambdaContainerHandler.handleRequest(SparkLambdaContainerHandler.java:61)
at com.amazonaws.serverless.proxy.internal.LambdaContainerHandler.proxy(LambdaContainerHandler.java:126)
at com.logindex.lambda.LambdaHandler.handleRequest(LambdaHandler.kt:35)
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)
22 Sep 2017 21:29:27 INFO LambdaEmbeddedServer - Called join method, nothing to do here since Lambda only runs a single event per container
END RequestId: 1a7fc844-9fdd-11e7-bdf6-7b809f4c7a77
REPORT RequestId: 1a7fc844-9fdd-11e7-bdf6-7b809f4c7a77	Duration: 1834.28 ms	Billed Duration: 1900 ms Memory Size: 256 MB	Max Memory Used: 56 MB

The text was updated successfully, but these errors were encountered:

sapessi · 2017-09-27T20:00:27Z

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

…f the embedded server object

sapessi · 2017-10-12T16:25:11Z

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 · 2017-10-30T14:52:40Z

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 · 2017-10-30T17:34:28Z

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 · 2017-11-21T15:52:35Z

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 · 2017-11-21T18:52:29Z

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 · 2017-11-21T18:55:25Z

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 · 2017-11-21T18:57:07Z

Cool, once done will test

sapessi · 2017-11-21T18:58:47Z

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

lskrajny · 2017-11-21T19:41:13Z

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 · 2017-11-21T19:47:14Z

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 :(

…ds to be called after the resources are defined

sapessi · 2017-11-21T20:00:30Z

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 · 2017-11-21T20:04:19Z

@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.

lskrajny changed the title ~~Spark: Cold start occassionally throws NullReference exception~~ Spark: Cold start occassionally throws NullPointer exception Sep 24, 2017

sapessi self-assigned this Sep 27, 2017

sapessi added the bug label Sep 27, 2017

sapessi referenced this issue Oct 12, 2017

Still flying blind, move Spark filter initialization to constructor o…

0433b6b

…f the embedded server object

sapessi added a commit that referenced this issue Nov 21, 2017

Upgraded to latest version of spark to try and address #71

6c1d159

sapessi added a commit that referenced this issue Nov 21, 2017

Added init method call for filter, still cannot replicate #71 in local

1f9e957

sapessi added a commit that referenced this issue Nov 21, 2017

Added the awaitInitialization() call as suggested in #71.

558565c

sapessi added a commit that referenced this issue Nov 21, 2017

Another commit for #71. Looks like the awaitInitialization method nee…

de73155

…ds to be called after the resources are defined

sapessi closed this as completed Nov 21, 2017

sapessi mentioned this issue Nov 21, 2017

Servlet improvements merge for 0.8 release #77

Merged

sapessi added this to the Release 0.8 milestone Nov 21, 2017

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Spark: Cold start occassionally throws NullPointer exception #71

Spark: Cold start occassionally throws NullPointer exception #71

lskrajny commented Sep 22, 2017 •

edited by sapessi

Loading

sapessi commented Sep 27, 2017

sapessi commented Oct 12, 2017

lskrajny commented Oct 30, 2017

sapessi commented Oct 30, 2017

sapessi commented Nov 21, 2017

lskrajny commented Nov 21, 2017

sapessi commented Nov 21, 2017

lskrajny commented Nov 21, 2017

sapessi commented Nov 21, 2017

lskrajny commented Nov 21, 2017 •

edited

Loading

sapessi commented Nov 21, 2017

sapessi commented Nov 21, 2017

sapessi commented Nov 21, 2017

Spark: Cold start occassionally throws NullPointer exception #71

Spark: Cold start occassionally throws NullPointer exception #71

Comments

lskrajny commented Sep 22, 2017 • edited by sapessi Loading

sapessi commented Sep 27, 2017

sapessi commented Oct 12, 2017

lskrajny commented Oct 30, 2017

sapessi commented Oct 30, 2017

sapessi commented Nov 21, 2017

lskrajny commented Nov 21, 2017

sapessi commented Nov 21, 2017

lskrajny commented Nov 21, 2017

sapessi commented Nov 21, 2017

lskrajny commented Nov 21, 2017 • edited Loading

sapessi commented Nov 21, 2017

sapessi commented Nov 21, 2017

sapessi commented Nov 21, 2017

lskrajny commented Sep 22, 2017 •

edited by sapessi

Loading

lskrajny commented Nov 21, 2017 •

edited

Loading