ExceptionInInitializerError when using spring with profile #234
Comments
|
I think the class loader is a red herring. Since you got the log output twice, it means the static code was executed twice, which in turn means you were running in a new instance of the function. Each instance is completely isolated so you would have a different instance of the class loader. I'm trying to replicate the issue in a unit test but I'm having little luck. The only way I can make the double-init happen is if I explicitly call the |
|
Any chance you can share your source code @shuangy92? |
|
@sapessi I tested with this project and attached some logs. |
|
I changed the lambda memory size from 1G to 2G, now the app can boot once with |
|
thanks @shuangy92 I'll keep testing and trying to replicate. I'll have to push this out to a future release because I want to get 1.3.1 out sooner rather than later. |
|
(Slightliy) more detailed explaination: #210 (comment) Make sure your static init code runs less than 10 seconds otherwise you will get a dual-init problem. Put the init in the handler callback with a null check like this (by @grsterin): |
|
@Noisyfox I tried this way, but it doesn't reduce my cold start time much. See my quote below.
I finally changed the lambda memory size to 3008M (which is the upper limit). Now it works fine. |
|
Well just checked the logs. 3008M memory only helps a little. Looks like once the issue happens, then it happens continuously, and vice versa. |
Even with the lazy-init approch? |
|
Hey @Noisyfox, @shuangy92 There is indeed a 10 seconds limit to the init time. If your class takes longer than 10 seconds to instantiate during the Lambda function init it will be automatically restarted. I see two ways around this. First a radical way:
Next, something that we could experiment with (I have not tried this myself so it's completely untested at the moment, just an idea off the top of my head):
|
|
I will implement solution #2, using a separate thread to make the most of the 10 seconds of initialization time, releasing the initialization latch when the ten seconds are over to allow Lambda to continue and use a second latch to hold the handler until the Spring application is initialized. I will make this an optional feature. |
|
That sounds very promising! |
and #234. Also added a new builder object that makes it easier to construct container handlers
|
This is on its way in release 1.4. See my last comment on #210 |
|
Release 1.4 is out on maven central. The release notes include a list of all the changes. Closing this issue. |
Scenario
At first I was using spring boot with spring profile, and I found that the application has a high possibility to launch twice.
The first launch is fast, and as soon as the log prints out
START RequestId：..., the second launch starts.It may happen at any time during the first launch. The farthest place the first launch can reach from my observation is to print out
o.s.j.e.a.AnnotationMBeanExporter : Registering beans for JMX exposure on startup.In 10 times of cold start, this issue happens like 8 times. (Yes some times the application do launch once only)
If the application only launches once, it takes ~10s. But for twice, it takes ~40s. The refreshing context for the second launch takes ~10s.
What I mean "launch twice" is that the static init block of
SpringBootLambdaContainerHandlerwas entered twice.I also tried to declare
SpringBootLambdaContainerHandleras a member attribute ofMyStreamLambdaHandler, and init it in the constructor. It shows that the constructor was also entered twice.I thought this can only happen when there's multiple class loaders. So I print out the loader and it's ancestors in the static init block like this:
The result is here:
First launch:
Second luanch:
As you can see, it's super weird that the same
AppClassLoaderhas differentExtClassLoaderas parent...I also tried to "lazy init" the handler as introduced at #201.
By this way, the application only launches once in
handleRequest, but it takes ~30s (~10s for refresh context).I then tried not to use profile, nothing changed.
I tried to reduced the dependecy and make the application almost the same to demo. The issue still exists.
Finally I found that as long as I'm using spring boot, this issue always happens.
BTW, I found someone who encountered the similar problem at here:
https://forum.serverless.com/t/aws-lambda-coldstart-springboot-booting-2-times/5850
Next, I removed all spring-boot dependecies and used spring only (with profile).
By this way, I got
ExceptionInInitializerErrordirectly. The log is here:But if I get rid of profile, the application launches once only.
I looked into the codes, and found that
initilizer.onStartupwas called twice at newHandler.activateSpringProfiles(profiles) and newHandler.initialize().I tried to remove L98 and the issue then disappers.
I'm not sure if this fix is correct... Any help is appreciated. I still want to use spring boot with profile but I need to reduced the cold start time.
=============== update
Just confirmed that remove L98 doesn't fix the issue. It happened again.
But this time the stack trace changes:
BTW, I printed the stack trace in the static init block. It's the same for both launches:
=============== update
Also needs to
initialized = trueafter initializer.setSpringProfiles(getServletContext(), profiles)Now the problem disappears again. But it's kinda hard for me to confirm the fix since it's a random issue...
=============== update
If the app is really small (like the demo), then the possibility the issue happens is greatly reduced.
For example, I tried to cold start >10 times, and only get 1 time of problem like this:
The text was updated successfully, but these errors were encountered: