8

Starting Jetty there's a long delay (8s) before my web application starts loading

13:50:10 [INFO] jetty-9.4.5.v20170502
13:50:18 [INFO] Scanning elapsed time=146ms

With debug logging turned on there are two interesting steps

  • Extracting dependent war-application, which takes time after all (3s)

    10:03:13 [DEBUG] Extracting entry = null from jar file:[..]/application-1.0.war
    10:03:16 [DEBUG] Unpacked overlay: jar:file:[..]/application-1.0.war!/ to file:[..]
    
  • and the below 4s delay:

    10:03:16 [DEBUG] Service loaders found in 0ms
    10:03:20 [DEBUG] loaded interface javax.servlet.ServletContainerInitializer
    

How can I debug or affect what's causing above 4s delay?


Configuration

pom.xml

<dependency>
    <groupId>com.company</groupId>
    <artifactId>application</artifactId>
    <version>1.0</version>
    <type>war</type>
</dependency>

[...]

<plugin>
    <groupId>org.eclipse.jetty</groupId>
    <artifactId>jetty-maven-plugin</artifactId>
    <version>9.4.5.v20170502</version>
    <configuration>
        <webApp>
            <webInfIncludeJarPattern>empty</webInfIncludeJarPattern>
            <containerIncludeJarPattern>empty</containerIncludeJarPattern>
        </webApp>
    </configuration>
</plugin>

web.xml

<web-app xmlns="http://xmlns.jcp.org/xml/ns/javaee"
     xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
     xsi:schemaLocation="http://xmlns.jcp.org/xml/ns/javaee http://xmlns.jcp.org/xml/ns/javaee/web-app_3_1.xsd" 
     version="3.1" 
     metadata-complete="true">

   <context-param>
       <param-name>contextClass</param-name>
       <param-value>org.springframework.web.context.support.AnnotationConfigWebApplicationContext</param-value>
   </context-param>

   <context-param>
       <param-name>contextConfigLocation</param-name>
       <param-value>com.app.AnnotationConfig</param-value>
   </context-param>

   <listener>
       <listener-class>org.springframework.web.context.ContextLoaderListener</listener-class>
   </listener>

   [...]

</web-app>
Johan Sjöberg
  • 47,929
  • 21
  • 130
  • 148
  • Theoretically you can always acquire a profiler such as visualvm and do a full profile run. Maybe the trial licence period is good enough to identify the culprit ... – GhostCat Aug 09 '17 at 12:26
  • do you have Spring in the mix? – diginoise Aug 09 '17 at 12:38
  • few more - how many classes / jars do you have in `WEB-INF\classes` and `WEB-INF\lib` respectively? did you try using quickstart module? – diginoise Aug 09 '17 at 12:46
  • @diginoise, Spring's in the mix yes. The entire project including `WEB-INF` is virtually empty but there is a dependent war project with some 70 MB jar-files. Running that application standalone though in the same way doesn't suffer the same delay – Johan Sjöberg Aug 09 '17 at 12:56
  • Also check that localhost or computer name is resolved in your host file. – Xvolks Aug 09 '17 at 12:57
  • @Xvolks It is :) – Johan Sjöberg Aug 09 '17 at 13:00
  • I supposed it was, else it should have took longer to start. – Xvolks Aug 09 '17 at 13:02
  • Would be good to exclude these big jar files from scanning for Servlet 3.1 annotations. I know you have `empty` `webInfIncludeJarPattern`. I would try also adding `containerIncludeJarPattern` in exactly the same manner. Also try setting DEBUG or INFO logging level for `org.eclipse.jetty.annotations.AnnotationConfiguration` to see whether your big jars are truly excluded. If these are baked into your WAR file, move them to `WEB-INF\lib` to test whether it is scanning. Perhaps you could get away with Servlet 2.5 which would stop scanning altogether. – diginoise Aug 09 '17 at 13:26
  • @diginoise `containerIncludeJarPattern` is for server (aka "the container") jars, don't mess with that one in a normal home/base (non-embedded) setup. an empty `webInfIncludeJarPattern` means scan it all (you essentially have it undefined). – Joakim Erdfelt Aug 09 '17 at 14:01
  • No change with `containerIncludeJarPattern` and no extra information with either maven debug `-X` or debug jetty logging https://stackoverflow.com/questions/8087794/logback-logging-with-maven-jetty-plugin. Also no change on startup time when switching to version from `3.1` to `2.5` in `web.xml` – Johan Sjöberg Aug 09 '17 at 14:19
  • maven `-X` has no relationship to jetty debug logging. That is merely the plugin's own debug logging. – Joakim Erdfelt Aug 09 '17 at 20:19

1 Answers1

4

You have a bigger then average webapp (70MB of WEB-INF/lib jars), but nothing colossally big (I've seen 800MB war files)

There's a few things that occur that could be cause for slow down.

  1. Unpacking the war into the WebApp temp directory
  2. Unpacking resource jars (WEB-INF/lib/*.jar!/META-INF/resources/) into the WebApp temp directory
  3. Jar bytecode scanning (for annotations and types declared in @HandlesType annotations on javax.servlet.ServletContainerInitializer classes)

If your filesystem is slow, then any of the above can slow you down.

Note: the DEBUG logging of Jetty will tell you the timing of each of those (even breaking down the timing of bytecode scanning timing to the individual jar)

The bytecode scanning step is the most often place where startup times take a hit.

Configuring the <containerIncludeJarPattern> for "empty" is not recommended, that is necessary for Servlets, JSPs, Taglibs to function.

The containerIncludeJarPattern default is only the servlet / jsp / taglib jars anyway. (which take microseconds to scan)

The <webInfIncludeJarPattern> should also not be just "empty", it should at a minimum include your WEB-INF/classes content (aka .*/classes/.*). Consider setting it up to only scan those WEB-INF/lib jars that you need. (something like .*/lib/spring-.*\.jar$|.*/classes/.*)

The size in bytes of the classes in your WEB-INF/lib/*.jar and WEB-INF/classes is actually irrelevant. What's more relevant to timing is the number of files found (even non-class files).

If you use resource jars (WEB-INF/lib/*.jar!/META-INF/resources/) then this is a significant penalty/source of your slow startup.

What you can do:

Start with looking at your DEBUG logs, that will tell you where things are taking their times.

Next, investigate using the quickstart features of Jetty if startup timing is important (this has 2 parts, a build-time component that scans and builds a jetty-quickstart.xml that is included in your war, and a runtime module that looks for and uses that jetty-quickstart.xml if found)

Finally, If you are using resource jars (WEB-INF/lib/*.jar!/META-INF/resources/), consider moving those contents out of WEB-INF/lib and into the normal places in your war during your build (package phase in maven). These are convenient, but have a bunch of side effects that you don't appear to like. (also consider the issue of conflicting resource resolution at runtime).

Joakim Erdfelt
  • 46,896
  • 7
  • 86
  • 136