Heroku fails to properly start a small Dropwizard app. The log however says that Jetty container be up and running on the port supplied by Heroku: org.eclipse.jetty.server.ServerConnector: Started
So, the Heroku status changes from starting to crashed. Then Heroku tries again and eventually dies with an "App boot timeout".
How can I further diagnose this?
2020-04-02T16:00:37.000000+00:00 app[api]: Build succeeded
2020-04-02T16:00:39.313741+00:00 app[web.1]: INFO [2020-04-02 16:00:39,257] io.dropwizard.assets.AssetsBundle: Registering AssetBundle with name: assets for path /assets/*
2020-04-02T16:00:39.313839+00:00 app[web.1]: INFO [2020-04-02 16:00:39,295] io.federecio.dropwizard.swagger.SwaggerHostResolver: Setting host for swagger to aa77d0bc-c110-47f6-86bd-26f789393da5
2020-04-02T16:00:39.313872+00:00 app[web.1]: INFO [2020-04-02 16:00:39,295] io.dropwizard.assets.AssetsBundle: Registering AssetBundle with name: assets for path /swagger-static/*
2020-04-02T16:00:39.314079+00:00 app[web.1]: WARN [2020-04-02 16:00:39,296] io.dropwizard.jetty.setup.ServletEnvironment: Overriding the existing servlet registered with the name: assets
2020-04-02T16:00:39.952166+00:00 app[web.1]: INFO [2020-04-02 16:00:39,880] io.dropwizard.server.ServerFactory: Starting open-data-smn
[...]
2020-04-02T16:00:40.355433+00:00 app[web.1]: INFO [2020-04-02 16:00:40,313] org.eclipse.jetty.server.handler.ContextHandler: Started i.d.j.MutableServletContextHandler@77bb0ab5{/admin,null,AVAILABLE}
2020-04-02T16:00:40.355434+00:00 app[web.1]: INFO [2020-04-02 16:00:40,319] org.eclipse.jetty.server.ServerConnector: Started open-data-smn@f19c9d2{HTTP/1.1}{0.0.0.0:41114}
2020-04-02T16:02:06.374564+00:00 heroku[web.1]: State changed from starting to crashed
2020-04-02T16:02:06.453536+00:00 heroku[web.1]: State changed from crashed to starting
2020-04-02T16:02:13.178022+00:00 app[web.1]: Setting JAVA_TOOL_OPTIONS defaults based on dyno size. Custom settings will override them.
2020-04-02T16:02:13.183227+00:00 app[web.1]: Picked up JAVA_TOOL_OPTIONS: -Xmx300m -Xss512k -XX:CICompilerCount=2 -Dfile.encoding=UTF-8
2020-04-02T16:02:14.900977+00:00 app[web.1]: INFO [2020-04-02 16:02:14,859] io.dropwizard.assets.AssetsBundle: Registering AssetBundle with name: assets for path /assets/*
2020-04-02T16:02:15.005957+00:00 app[web.1]: INFO [2020-04-02 16:02:14,923] io.federecio.dropwizard.swagger.SwaggerHostResolver: Setting host for swagger to 385e560c-52cd-4239-94dd-8d7a2cc11993
2020-04-02T16:02:15.006049+00:00 app[web.1]: INFO [2020-04-02 16:02:14,924] io.dropwizard.assets.AssetsBundle: Registering AssetBundle with name: assets for path /swagger-static/*
2020-04-02T16:02:15.015815+00:00 app[web.1]: WARN [2020-04-02 16:02:14,924] io.dropwizard.jetty.setup.ServletEnvironment: Overriding the existing servlet registered with the name: assets
2020-04-02T16:02:15.829866+00:00 app[web.1]: INFO [2020-04-02 16:02:15,778] io.dropwizard.server.ServerFactory: Starting open-data-smn
[...]
2020-04-02T16:02:16.433772+00:00 app[web.1]: INFO [2020-04-02 16:02:16,401] org.eclipse.jetty.server.handler.ContextHandler: Started i.d.j.MutableServletContextHandler@77bb0ab5{/admin,null,AVAILABLE}
2020-04-02T16:02:16.433901+00:00 app[web.1]: INFO [2020-04-02 16:02:16,407] org.eclipse.jetty.server.ServerConnector: Started open-data-smn@f19c9d2{HTTP/1.1}{0.0.0.0:40280}
2020-04-02T16:02:42.603642+00:00 heroku[router]: at=error code=H20 desc="App boot timeout" method=GET path="/" host=open-data-smn.herokuapp.com request_id=c0b90d4d-56cb-4f89-9a10-e058c3082afd fwd="62.12.132.2" dyno= connect= service= status=503 bytes= protocol=https
2020-04-02T16:03:40.488419+00:00 heroku[web.1]: State changed from starting to crashed
2020-04-02T16:03:41.814453+00:00 heroku[router]: at=error code=H20 desc="App boot timeout" method=GET path="/" host=open-data-smn.herokuapp.com request_id=d93055b5-c12d-40e6-93db-2375b108b5c2 fwd="62.12.132.2" dyno= connect= service= status=503 bytes= protocol=https
Tuns out that configuring the server port in the application configuration YAML file like so
server:
port: $PORT
appears to work for Spring Boot apps but not for mine. For Dropwizard the only(?) option is to pass it as a JVM environment variable in the Procfile as per https://devcenter.heroku.com/articles/setting-the-http-port-for-java-applications#dropwizard.
Hence, the Dropwizard app did start and it did bind to a port - just not the one the Heroku web dyno had reserved. The dyno waited for some socket to bind to that port and eventually timed out.