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 IllegalStateException
s:
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 initializedThreadLocal
. 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 FilterDefinition
s 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 SitebricksModule
s 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.
Hi,
I have added a comment in google guice issue 597 after having read this article which helped me to understand my own similar situation:
http://code.google.com/p/googl…
Thx
Hi Remi,
I’m glad you’ve found this post useful 🙂
I’ve also had a similar problem like yours, except DBCP occasionally was throwing an exception saying “Connection already closed” or something, which again means that the current Unit Of Work did not end correctly, which inevitably will cause the situation we’re given a thread with an already initialized ORM session.
I did not want to bother with DBCP fine tuning, I just replaced it with BoneCP:
http://jolbox.com/
, and everything seems to work fine now.
Excellent post. Just ran into a similar problem. It turned out to be the interplay between the Shiro web filter and the Guice persist filter.