TL;DR: Using Google Guice with its servlet extension, be very careful when adding your filters from nested modules. The filter chain order could be the opposite to that you might expect. When using Sitebricks, override SitebricksModule method servletModule, extend the returned SitebricksServletModule with overriden configurePreFilters, configurePostFilters, or configureCustomServlets methods.

Preface

For some time already, I have a hobby/free time project I develop and maintain. It is a CMS for presentation kind of content for really large screens (up to 70in), based on the Sitebricks web framework, Google Guice with the guice-persist (Hibernate, JPA) module and a MySQL database.

The reason behind such a choice of technologies was that I’ve always wanted to experiment with the Sitebricks project, since it looked so promising to me. And, I have to say, it was really worth my time, hell, it is really worth every Java web developer’s time.

The CMS part of the project went in a really fast pace, and in about a month we were ready to deploy the thing to the production.

The Problem

Everything went smooth for some time, apparently while the production system had not been actualy used very much, until we noticed those IllegalStateExceptions:

Work already begun on this thread. Looks like you have called UnitOfWork.begin() twice without a balancing call to end() in between.

I have to say this at once: of course, every possible code path was examined, and every piece of code working with the database occurred between those methods.

The Investigation

Unit of Work is a common pattern for keeping track of the changes made during a single business transaction, in webapps, it is typically a single HTTP request. It is used in Guice Persist, although, I guess, the most used implementation is Spring’s OpenSessionInViewFilter.

Like the exception message above says, it is essential to enclose all the persistence-related operations between those symmetrical method calls – begin and end. In Java webapps, it is typically done in a filter like this:

public class MyWebappPersistFilter implements Filter {
    private final UnitOfWork unitOfWork; //inject this somehow

    /* some initialization/unrelated code*/

    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {            
        unitOfWork.begin();
        try {
            chain.doFilter(request, response);
        }
        finally {
            unitOfWork.end();
        }
    }
}

So, the HTTP request arrives, we begin our unit of work, pass all the request processing further the FilterChain, and after everything is done, we end our work. Notice the finally, block, it guarantees that the end portion of the code will be executed even when an exception is thrown.

Guice Persist recommends using its own PersistFilter and adding in user’s Guice modules:

public class MyModule extends ServletModule {
    public void configureServlets() {
      filter("/*").through(PersistFilter.class);

      serve("/index.html").with(MyHtmlServlet.class);
      // Etc.       
    }
}

Going back to the abovementioned exception message, of course, I checked the code thoroughly and verified that every piece of code that touches our data is within a Unit of work. Hell, I even started to think that I’m a victim of a global conspiracy and started experimenting with Jetty’s connector configurations thinking that switching off NIO would help. Actually it did a little, because Guice’s JpaPeristModule keeps track of unit of work’s context in a ThreadLocal, and turning off NIO apparently forced Jetty not to re-use threads so much, but creating new ones instead. The problem, though, still appeared but not so frequently, the system became actually usable.

The Cause

One day, I tried to reproduce the same problem in a minimal webapp, adding and configuring frameworks our project depends on one by one – Guice, Guice Persist, Hibernate and, finally, Sitebricks. And the problem started to reproduce again. In my persist filter, I added logging of the current thread id, and the HTTP request path, and, upon every single request to the page, the webapp added these lines:

DEBUG me.barinskis.conman.webapp.guice.filter.WebappPersistFilter - Begin UnitOfWork, servletPath: /s/site.css, thread id: 20
DEBUG me.barinskis.conman.webapp.guice.filter.WebappPersistFilter - Ended UnitOfWork, servletPath: /s/site.css, thread id: 20
DEBUG me.barinskis.conman.webapp.guice.filter.WebappPersistFilter - Begin UnitOfWork, servletPath: /favicon.ico, thread id: 18
DEBUG me.barinskis.conman.webapp.guice.filter.WebappPersistFilter - Ended UnitOfWork, servletPath: /favicon.ico, thread id: 18

Notice that there are NO requests logged that originate those requests to the site.css and favicon.ico resources, i.e., requests to the Sitebricks-backed page itself.

So, what happens there? This:

• An HTTP request arrives to the page, generated by the Sitebricks framework
• Our persist filter, for some mysterious reason, has not begun a new Unit Of Work
• Guice’s JpaPersistService begins the unit of work anyway automatically…
• … but “forgets” to close it
• The requested page is generated though
• Next HTTP request arrives
• At some point, Jetty dispatches the same thread from its thread pool that was used to process the previous request.
• The page tries to initialize new unit of work – either explicitly through our persist filter or implicitly if that filter has not been called.
• In that thread, since UnitOfWork has not been ended, still lives an initialized ThreadLocal.
• IllegalStateException is being thrown

The cause of the problem must be something related to the servlet filter configuration. Let’s see how our little app is configured:

public class WebappServletModule extends ServletModule {
    @Override
    protected void configureServlets() {
        filter("/*").through(WebappPersistFilter.class);

        install(new SitebricksModule() {
            @Override
            protected void configureSitebricks() {
                scan(PeopleList.class.getPackage());
            }
        });
    }
}

Everything looks correct, doesn’t it? Our persist filter is added according to the recommendations – the first one, after that we install the SitebricksModule, which, behind the scenes, installs a SitebricksFilter, which should be processed after our persist filter.

Actually, not. Guice’s ServletModule does not actually add a FilterDefinition after the user calls this filter...through method chain. In these methods, it collects all the FilterDefinitions added to this particular ServletModule and actually installs them after configureServlets method exits. And, since configuration of the SitebricksModule is finished sooner than our main webapps module, the WebappServletModule, we have the following chain of filters:

HiddenMethodFilter -> SitebricksFilter -> WebappPersistFilter

Hence, the exception.

The Solution

Luckily, Sitebricks authors have provided us a way how to overcome this – by extending SitebricksServletModule and overriding the SitebricksModules method servletModule:

public class WebappServletModule extends ServletModule {
    @Override
    protected void configureServlets() {
        bind(new TypeLiteral<UnitOfWorkStrategy<HttpServletRequest>>(){}).to(HttpRequestUnitOfWorkStrategy.class);

        install(new SitebricksModule() {
            @Override
            protected void configureSitebricks() {
                scan(PeopleList.class.getPackage());
            }

            @Override
            protected SitebricksServletModule servletModule() {
                return new SitebricksServletModule() {
                    @Override
                    protected void configurePreFilters() {
                        filter("/*").through(WebappPersistFilter.class);
                    }
                };
            }
        });
    }
}

That way we get the filter chain we wanted:

WebappPersistFilter -> HiddenMethodFilter -> SitebricksFilter

Conclusion

Well, pretty lame, huh? I wish Sitebricks’ or Guice’s documentation was more explicit about these issues with filter installation inside a nested module, since installing a OSIF-like filters could well be the most common scenario.

I also wish Guice Persist’s JpaPersistService did not implicitly start a new unit of work, but threw an exception instead. That would automatically eliminate some bad design decisions or just random slips people sometimes do.