Spring-boot application won't boot at startup inside docker

Question

I am running a simple spring-boot application inside a docker container. At startup whether started with java -jar MY_JAR.jar or mvn spring-boot:run the application will always hang at the following point:

2014-12-22 23:26:58.957  INFO 1 --- [ost-startStop-1] o.s.b.c.embedded.FilterRegistrationBean  : Mapping filter: 'hiddenHttpMethodFilter' to: [/*]

Here's the catch, I can ONLY reproduce this on an Ubuntu 14.04 box in DigitalOcean (1CPU, 1GB MEM), even though it's running inside a container. On my local machine (mac) everything runs fine.

The Dockerfile:

FROM java:8
ADD target/MY_SERVICE-1.0-SNAPSHOT.jar /data/svc.jar
EXPOSE 8080
CMD ["java", "-jar", "/data/svc.jar"]

Things I've Tried

• Give JVM more memory (75% of machine total)
• Intstalling the haveged library as suggested here
• Every other version of java I could get my hands on

Any suggestions?

Thanks for any help.

The whole log (started with --debug):

[Text Art Omitted]

 :: Spring Boot ::       (v1.1.10.RELEASE)

2014-12-22 19:22:58.375  INFO 20816 --- [           main] com.spectrom.uploadService.Main          : Starting Main on spectrom-services with PID 20816 (/root/spectrom-upload-service/target/upload-service-1.0-SNAPSHOT.jar started by root in /root/spectrom-upload-service)
2014-12-22 19:22:58.392 DEBUG 20816 --- [           main] o.s.boot.SpringApplication               : Loading source class com.spectrom.uploadService.Main
2014-12-22 19:22:58.671 DEBUG 20816 --- [           main] o.s.b.c.c.ConfigFileApplicationListener  : Skipped config file 'file:./config/application.yaml' resource not found
2014-12-22 19:22:58.673 DEBUG 20816 --- [           main] o.s.b.c.c.ConfigFileApplicationListener  : Skipped config file 'file:./config/application.properties' resource not found
2014-12-22 19:22:58.674 DEBUG 20816 --- [           main] o.s.b.c.c.ConfigFileApplicationListener  : Skipped config file 'file:./config/application.yml' resource not found
2014-12-22 19:22:58.675 DEBUG 20816 --- [           main] o.s.b.c.c.ConfigFileApplicationListener  : Skipped config file 'file:./application.yaml' resource not found
2014-12-22 19:22:58.675 DEBUG 20816 --- [           main] o.s.b.c.c.ConfigFileApplicationListener  : Skipped config file 'file:./application.properties' resource not found
2014-12-22 19:22:58.676 DEBUG 20816 --- [           main] o.s.b.c.c.ConfigFileApplicationListener  : Skipped config file 'file:./application.yml' resource not found
2014-12-22 19:22:58.677 DEBUG 20816 --- [           main] o.s.b.c.c.ConfigFileApplicationListener  : Skipped config file 'classpath:/config/application.yaml' resource not found
2014-12-22 19:22:58.678 DEBUG 20816 --- [           main] o.s.b.c.c.ConfigFileApplicationListener  : Skipped config file 'classpath:/config/application.properties' resource not found
2014-12-22 19:22:58.679 DEBUG 20816 --- [           main] o.s.b.c.c.ConfigFileApplicationListener  : Skipped config file 'classpath:/config/application.yml' resource not found
2014-12-22 19:22:58.679 DEBUG 20816 --- [           main] o.s.b.c.c.ConfigFileApplicationListener  : Skipped config file 'classpath:/application.yaml' resource not found
2014-12-22 19:22:58.680 DEBUG 20816 --- [           main] o.s.b.c.c.ConfigFileApplicationListener  : Loaded config file 'classpath:/application.properties'
2014-12-22 19:22:58.681 DEBUG 20816 --- [           main] o.s.b.c.c.ConfigFileApplicationListener  : Skipped config file 'classpath:/application.yml' resource not found
2014-12-22 19:22:58.693  INFO 20816 --- [           main] ationConfigEmbeddedWebApplicationContext : Refreshing org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@ddd51a7: startup date [Mon Dec 22 19:22:58 EST 2014]; root of context hierarchy
2014-12-22 19:22:58.708 DEBUG 20816 --- [           main] ationConfigEmbeddedWebApplicationContext : Bean factory for org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@ddd51a7: org.springframework.beans.factory.support.DefaultListableBeanFactory@47649f10: defining beans [org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor,main]; root of factory hierarchy
2014-12-22 19:23:00.964  INFO 20816 --- [           main] o.s.b.f.s.DefaultListableBeanFactory     : Overriding bean definition for bean 'beanNameViewResolver': replacing [Root bean: class [null]; scope=; abstract=false; lazyInit=false; autowireMode=3; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=org.springframework.boot.autoconfigure.web.ErrorMvcAutoConfiguration$WhitelabelErrorViewConfiguration; factoryMethodName=beanNameViewResolver; initMethodName=null; destroyMethodName=(inferred); defined in class path resource [org/springframework/boot/autoconfigure/web/ErrorMvcAutoConfiguration$WhitelabelErrorViewConfiguration.class]] with [Root bean: class [null]; scope=; abstract=false; lazyInit=false; autowireMode=3; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=org.springframework.boot.autoconfigure.web.WebMvcAutoConfiguration$WebMvcAutoConfigurationAdapter; factoryMethodName=beanNameViewResolver; initMethodName=null; destroyMethodName=(inferred); defined in class path resource [org/springframework/boot/autoconfigure/web/WebMvcAutoConfiguration$WebMvcAutoConfigurationAdapter.class]]
2014-12-22 19:23:02.480 DEBUG 20816 --- [           main] ationConfigEmbeddedWebApplicationContext : Unable to locate MessageSource with name 'messageSource': using default [org.springframework.context.support.DelegatingMessageSource@177df6c1]
2014-12-22 19:23:02.481 DEBUG 20816 --- [           main] ationConfigEmbeddedWebApplicationContext : Using ApplicationEventMulticaster [org.springframework.context.event.SimpleApplicationEventMulticaster@4ed304f3]
2014-12-22 19:23:03.647 DEBUG 20816 --- [           main] .t.TomcatEmbeddedServletContainerFactory : Code archive: /root/spectrom-upload-service/target/upload-service-1.0-SNAPSHOT.jar
2014-12-22 19:23:03.648 DEBUG 20816 --- [           main] .t.TomcatEmbeddedServletContainerFactory : Code archive: /root/spectrom-upload-service/target/upload-service-1.0-SNAPSHOT.jar
2014-12-22 19:23:03.648 DEBUG 20816 --- [           main] .t.TomcatEmbeddedServletContainerFactory : None of the document roots [src/main/webapp, public, static] point to a directory and will be ignored.
2014-12-22 19:23:03.691  INFO 20816 --- [           main] .t.TomcatEmbeddedServletContainerFactory : Server initialized with port: 8080
2014-12-22 19:23:04.855  INFO 20816 --- [           main] o.apache.catalina.core.StandardService   : Starting service Tomcat
2014-12-22 19:23:04.856  INFO 20816 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet Engine: Apache Tomcat/7.0.57
2014-12-22 19:23:05.008  INFO 20816 --- [ost-startStop-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2014-12-22 19:23:05.009  INFO 20816 --- [ost-startStop-1] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 6326 ms
2014-12-22 19:23:06.928  INFO 20816 --- [ost-startStop-1] o.s.b.c.e.ServletRegistrationBean        : Mapping servlet: 'dispatcherServlet' to [/]
2014-12-22 19:23:06.933  INFO 20816 --- [ost-startStop-1] o.s.b.c.embedded.FilterRegistrationBean  : Mapping filter: 'hiddenHttpMethodFilter' to: [/*]

After the ^c:

^C2014-12-22 19:24:28.771  INFO 20816 --- [       Thread-2] ationConfigEmbeddedWebApplicationContext : Closing org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@ddd51a7: startup date [Mon Dec 22 19:22:58 EST 2014]; root of context hierarchy
2014-12-22 19:24:28.815  WARN 20816 --- [       Thread-2] ationConfigEmbeddedWebApplicationContext : Exception thrown from LifecycleProcessor on context close

java.lang.IllegalStateException: LifecycleProcessor not initialized - call 'refresh' before invoking lifecycle methods via the context: org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@ddd51a7: startup date [Mon Dec 22 19:22:58 EST 2014]; root of context hierarchy
    at org.springframework.context.support.AbstractApplicationContext.getLifecycleProcessor(AbstractApplicationContext.java:359)
    at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:890)
    at org.springframework.boot.context.embedded.EmbeddedWebApplicationContext.doClose(EmbeddedWebApplicationContext.java:141)
    at org.springframework.context.support.AbstractApplicationContext$1.run(AbstractApplicationContext.java:811)

Thread Dump during hang:

2014-12-23 01:09:58
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.25-b02 mixed mode):

"localhost-startStop-1" #13 daemon prio=5 os_prio=0 tid=0x00007f56c431a800 nid=0x12 runnable [0x00007f56e0bec000]
   java.lang.Thread.State: RUNNABLE
    at java.io.FileInputStream.readBytes(Native Method)
    at java.io.FileInputStream.read(FileInputStream.java:246)
    at sun.security.provider.SeedGenerator$URLSeedGenerator.getSeedBytes(SeedGenerator.java:539)
    at sun.security.provider.SeedGenerator.generateSeed(SeedGenerator.java:144)
    at sun.security.provider.SecureRandom$SeederHolder.<clinit>(SecureRandom.java:203)
    at sun.security.provider.SecureRandom.engineNextBytes(SecureRandom.java:221)
    - locked <0x00000000f10478f8> (a sun.security.provider.SecureRandom)
    at java.security.SecureRandom.nextBytes(SecureRandom.java:457)
    - locked <0x00000000f1047c18> (a java.security.SecureRandom)
    at java.security.SecureRandom.next(SecureRandom.java:480)
    at java.util.Random.nextInt(Random.java:329)
    at org.apache.catalina.util.SessionIdGenerator.createSecureRandom(SessionIdGenerator.java:246)
    at org.apache.catalina.util.SessionIdGenerator.getRandomBytes(SessionIdGenerator.java:183)
    at org.apache.catalina.util.SessionIdGenerator.generateSessionId(SessionIdGenerator.java:153)
    at org.apache.catalina.session.ManagerBase.startInternal(ManagerBase.java:573)
    at org.apache.catalina.session.StandardManager.startInternal(StandardManager.java:485)
    - locked <0x00000000f0fa82e0> (a org.apache.catalina.session.StandardManager)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    - locked <0x00000000f0fa82e0> (a org.apache.catalina.session.StandardManager)
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5501)
    - locked <0x00000000f68e5d68> (a org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedContext)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    - locked <0x00000000f68e5d68> (a org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedContext)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1575)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1565)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

"Tomcat-startStop-1" #12 daemon prio=5 os_prio=0 tid=0x00007f56c8405000 nid=0x11 waiting on condition [0x00007f56f4103000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000f69aa980> (a java.util.concurrent.FutureTask)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:429)
    at java.util.concurrent.FutureTask.get(FutureTask.java:191)
    at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:1123)
    - locked <0x00000000f68505c0> (a org.apache.catalina.core.StandardHost)
    at org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:816)
    - locked <0x00000000f68505c0> (a org.apache.catalina.core.StandardHost)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    - locked <0x00000000f68505c0> (a org.apache.catalina.core.StandardHost)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1575)
    at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1565)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

"DestroyJavaVM" #10 prio=5 os_prio=0 tid=0x00007f56f0009800 nid=0x7 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"main" #9 prio=5 os_prio=0 tid=0x00007f56f0159800 nid=0x10 waiting on condition [0x00007f56f4cf0000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000f69aac08> (a java.util.concurrent.FutureTask)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:429)
    at java.util.concurrent.FutureTask.get(FutureTask.java:191)
    at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:1123)
    - locked <0x00000000f68d1648> (a org.apache.catalina.core.StandardEngine)
    at org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:300)
    - locked <0x00000000f68d1648> (a org.apache.catalina.core.StandardEngine)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    - locked <0x00000000f68d1648> (a org.apache.catalina.core.StandardEngine)
    at org.apache.catalina.core.StandardService.startInternal(StandardService.java:443)
    - locked <0x00000000f68d1648> (a org.apache.catalina.core.StandardEngine)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    - locked <0x00000000f6850418> (a org.apache.catalina.core.StandardService)
    at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:739)
    - locked <0x00000000f6850590> (a [Lorg.apache.catalina.Service;)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    - locked <0x00000000f683f5d8> (a org.apache.catalina.core.StandardServer)
    at org.apache.catalina.startup.Tomcat.start(Tomcat.java:341)
    at org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedServletContainer.initialize(TomcatEmbeddedServletContainer.java:85)
    - locked <0x00000000f68c4660> (a org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedServletContainer)
    at org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedServletContainer.<init>(TomcatEmbeddedServletContainer.java:74)
    at org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedServletContainerFactory.getTomcatEmbeddedServletContainer(TomcatEmbeddedServletContainerFactory.java:377)
    at org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedServletContainerFactory.getEmbeddedServletContainer(TomcatEmbeddedServletContainerFactory.java:153)
    at org.springframework.boot.context.embedded.EmbeddedWebApplicationContext.createEmbeddedServletContainer(EmbeddedWebApplicationContext.java:148)
    - locked <0x00000000f5dd9708> (a org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext)
    at org.springframework.boot.context.embedded.EmbeddedWebApplicationContext.onRefresh(EmbeddedWebApplicationContext.java:121)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:476)
    - locked <0x00000000f5de2550> (a java.lang.Object)
    at org.springframework.boot.context.embedded.EmbeddedWebApplicationContext.refresh(EmbeddedWebApplicationContext.java:109)
    at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:691)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:320)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:952)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:941)
    at com.spectrom.uploadService.Main.main(Main.java:17)
    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:483)
    at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:53)
    at java.lang.Thread.run(Thread.java:745)

"Service Thread" #7 daemon prio=9 os_prio=0 tid=0x00007f56f00cd000 nid=0xe runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007f56f00ca000 nid=0xd waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007f56f00c8000 nid=0xc waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007f56f00c6000 nid=0xb waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007f56f009a000 nid=0xa in Object.wait() [0x00007f56f5500000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f5bb8068> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:142)
    - locked <0x00000000f5bb8068> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:158)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007f56f0097800 nid=0x9 in Object.wait() [0x00007f56f5601000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000f5bb8220> (a java.lang.ref.Reference$Lock)
    at java.lang.Object.wait(Object.java:502)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:157)
    - locked <0x00000000f5bb8220> (a java.lang.ref.Reference$Lock)

"VM Thread" os_prio=0 tid=0x00007f56f0090800 nid=0x8 runnable

"VM Periodic Task Thread" os_prio=0 tid=0x00007f56f00dc800 nid=0xf waiting on condition

JNI global references: 29

Heap
 def new generation   total 13696K, used 12232K [0x00000000f0600000, 0x00000000f14d0000, 0x00000000f5950000)
  eden space 12224K,  88% used [0x00000000f0600000, 0x00000000f1082050, 0x00000000f11f0000)
  from space 1472K, 100% used [0x00000000f11f0000, 0x00000000f1360000, 0x00000000f1360000)
  to   space 1472K,   0% used [0x00000000f1360000, 0x00000000f1360000, 0x00000000f14d0000)
 tenured generation   total 30240K, used 20916K [0x00000000f5950000, 0x00000000f76d8000, 0x0000000100000000)
   the space 30240K,  69% used [0x00000000f5950000, 0x00000000f6dbd1b0, 0x00000000f6dbd200, 0x00000000f76d8000)
 Metaspace       used 23431K, capacity 23620K, committed 23728K, reserved 1071104K
  class space    used 2909K, capacity 2974K, committed 2992K, reserved 1048576K

Answer 1

Got it! Once I installed haveged on the host, the process immediately moved forward, and spring booted fine. I will post more once I do a bit more research into how docker interacts with haveged on the host.

In summary the following command issued on the host will fix the the issue:

apt-get install haveged -y

If anyone has a detailed understanding of this, feel free to post!

The thing that I don't understand at the moment, is why the host machine needed extra code, and everything wasn't isolated within the docker container.

Answer 2

For those who might come here later. I think easiest solution is to modify Dockerfile and have entry point as follows:

ENTRYPOINT ["java", **"-Djava.security.egd=file:/dev/./urandom"**,"-jar","app.jar"]

Had experience with apps hanging anywhere between 30 seconds and 15 minutes (or maybe more, but got killed).

From the other post that shares details:

Without this, Java uses /dev/random to seed its SecureRandom class, which can cause Java code to block unexpectedly.

Alternatively, in the $JAVA_HOME/jre/lib/security/java.security configuration file, add the line

securerandom.source=file:/dev/./urandom

Footnote: In the above examples, you need the crazy-looking filename, e.g., the extra /./, to trick Java into accepting your filename. If you just use /dev/urandom, Java decides you didn't really mean it and replaces what you wrote with /dev/random. Craziness!