startAsync / task {} controller methods produce unreliable results.

[donald-jackson]

When using startAsync or task {} in controller methods for asynchronous processing, output is unreliable. By unreliable I mean that Hibernate (or wherever the issue lies) is producing semi-random output. Steps to reproduce:

To duplicate:

1. Clone the repository at https://github.com/donald-jackson/grails-async-error-demo.git
2. 'run-app' in Grails and visit /AsyncErrorTest/systemSetting
3. Create a setting with optionName = 'testOption' set value to true (or false)
4. Run the script created (update URL as necessary)
   • php produce_error.php "http://localhost:8080/AsyncErrorTest/systemSetting/showVariable"
5. The first run should work correctly, then run
   • php produce_error.php "http://localhost:8080/AsyncErrorTest/systemSetting/showVariableAsync"
6. The second run should also work correctly.
7. Change the variable value to the opposite of what set in step 3 (true/false)
8. Run
   • php produce_error.php "http://localhost:8080/AsyncErrorTest/systemSetting/showVariableAsync"
9. Variables should be flipping around.
10. Once you notice this behaviour you can check in your browser or even on the original showVariable method and it will also give unreliable output.

Tested on Mac OS X 10.10.2 - grails 2.5.1

Java details:
java version "1.8.0_20"
Java(TM) SE Runtime Environment (build 1.8.0_20-b26)
Java HotSpot(TM) 64-Bit Server VM (build 25.20-b23, mixed mode)

[gregopet]

Will run the above demo when on another computer but this looks similar to our problem: Hibernate sessions fetch stale data when using async controllers and long polling

[gregopet]

It's the same bug we've hit and it basically renders aync controller actions useless - IMHO this bug should be tagged as blocker because you can do something almost completely copied from the user manual and get your app in serious, hard to pinpoint trouble. I've put together a simpler app, no need to run scripts, just refresh a page. You can download it here and open localhost:8080/asyncbug, then just keep refreshing the page. After about 40 refreshes (on my machine at least) the app starts behaving randomly: random old values are retrieved from the database.

Besides a simple Counter domain class that contains a single property Integer count, it all happens in a single action of a controller:

def index() {
    def ctx = startAsync()
    ctx.start {
        def counter = Counter.first()
        if (counter) {
            counter.count++
            try {
                counter.save(failOnError:true, flush:true)
                render text:"You have refreshed this page ${counter.count} times"
            } catch (Throwable t) {
                render text:"Error trying to save object, counter said you refreshed ${counter.count} times"
            }
        } else {
            counter = new Counter()
            counter.save(failOnError:true, flush:true)
            render text:"First refresh, created refresh counter"
        }
        ctx.complete()
    }
}

I am almost certain Hibernate sessions are not getting closed and are later reused either after exiting the async controller block or after exiting the controller action. If I lower the number of maximum connections in the connection pool to 2, I will get Timeout: Pool empty. Unable to fetch a connection in 10 seconds, none available[size:2; busy:2; idle:0; lastwait:10000] after ~10 refreshes at which point the app gets firmly stuck for minutes before a connection is available again.

If I explicitly close the session at the end of requests (via e.g. Domain.withSession { it.close() }) I will get org.springframework.orm.hibernate4.HibernateSystemException: Session is closed! exceptions on a following invocation, originating from the def counter = Counter.first() line.

As we are using async controllers in production already and have only recently connected various random problems to this bug, I would really appreciate a workaround if one is possible before 2.5.2 is released!

[gregopet]

It also seems the bug is fixed in 3.0.7.

[donald-jackson]

As you say you can copy/paste examples from the manual and run into this issue. Any chance this will be fixed in the 2.5.x branch as in some cases significant effort is required to upgrade to 3.x

[graemerocher]

Thanks for the feedback guys, I have marked it is a blocker and we will look at doing a 2.5.2 release soon.

[gregopet]

Great, thanks, let us know if we can offer any further help!

[tupusun]

I met with this issue in release 2.5.1 too.
A workaround is to clear the session in a grails filter's "before" closure.
However, this could only help on fixing the stale object issue. Another issue related is that the database connection could not be recovered when underlying connection is broken, either by database itself or network failure. the whole application has to be restarted to restore connection under this case. According to my knowledge, there seems no easy way to work around this with perfect result.

I have to say, this is really a nasty issue, it blocks the async function to be used in production mode. A fix should be available as soon as possible.

[graemerocher]

I will be looking at 2.5.x issues next week as soon as 3.0.8 is done...

[donald-jackson]

Thank you Graeme, much appreciated

[tupusun]

Has a try on the snapshot build, and found the issue is fixed perfect. Thanks Graeme.

When will the grails v2.5.2 be available?