Why do some requests answered by a Filter take over a second on AppEngine?

[lyz984]

I have a modular application running on appengine. Since each module has it's own resources (static files) I use a Filter to serve these resources.

My problem is that some resources take over one second to be served while others are served fast.

As you can see below I already measured the time my Filter takes... This is always around a few milliseconds. Where could the extra second come from?It is not the startup time of the appengine since it was already startet by the html request.

I use Guice to call the Filter and the side itself is served by Wicket.

Here is the code of my ServletModule:

filter("/*").through(ResourceFilter.class);

filter("/*").through(WicketFilter.class, new HashMap<String, String>() {{
    put("injectorContextAttribute", Injector.class.getName());
    if (deployment) {
        put("configuration", "deployment");
    }
    put(WicketFilter.FILTER_MAPPING_PARAM, "/*");
    put(WicketFilter.IGNORE_PATHS_PARAM, ignorePaths);
    put(WicketFilter.APP_FACT_PARAM, GuiceWebApplicationFactory.class.getName());
}});
bind(WicketFilter.class).in(Singleton.class);

And this is the code of my Filter:

@Singleton
public class ResourceFilter implements Filter {

    private static final Logger LOGGER = LoggerFactory.getLogger(ResourceFilter.class);

    private final RootSite rootSite;

    @Inject
    public ResourceFilter(RootSite rootSite) {
       this.rootSite = rootSite;
    }

    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
        long start = System.currentTimeMillis();
        URL resource = null;
        String path;
        if (request instanceof HttpServletRequest) {
            path = ((HttpServletRequest) request).getRequestURI();
            resource = rootSite.getResource(path);
        } else {
            path = null;
        }
        if (resource != null) {
            try (InputStream in = resource.openStream();
                 OutputStream out = response.getOutputStream()) {
                String contentType;
                if (resource.getPath().endsWith(".html")) {
                    contentType = "text/html";
                } else if (resource.getPath().endsWith(".css")) {
                    contentType = "text/css";
                } else {
                    contentType = "application/octet-stream";
                }
                response.setContentType(contentType);
                byte[] bytes = new byte[4096];
                int len;
                while ((len = in.read(bytes)) > 0) {
                    out.write(bytes, 0, len);
                }
            }
        } else if (chain != null) {
            chain.doFilter(request, response);
        }
        long time = System.currentTimeMillis() - start;
        LOGGER.info(path + ": " + time + " ms");
    }

}

[sami...@google.com]

As you have mentioned in the thread that the issue is not related to app engine, I would highly recommend checking out the documentation for best practices for App Engine startup time in the following Article.

Also, I would highly recommend posting the issue in community sites such as StackOverflow, Serverfault or StackExchange as there are a range of similar issues that were resolved by the users themselves through communicating with each other.

[lyz984]

I should point out that this behavior is not limited to the first request. It happens on almost all reloads of the page but strange not on all.