@UnitOfWork action sometimes throws UnitOfWork.begin() twice exception.

[smallufo]

My action is read-only. It only calls some injected DAO's get / list methods.

After I annotated the action @UnitOfWork (to get rid of the previous problem) , it sometimes throws exception :

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

at com.google.inject.internal.util.$Preconditions.checkState(Preconditions.java:142) ~[guice-3.0.jar:na]

at com.google.inject.persist.jpa.JpaPersistService.begin(JpaPersistService.java:66) ~[guice-persist-3.0.jar:na]

at ninja.jpa.UnitOfWorkInterceptor.invoke(UnitOfWorkInterceptor.java:53) ~[ninja-core-3.1.1.jar:na]

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0-ea]

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.8.0-ea]

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0-ea]

at java.lang.reflect.Method.invoke(Method.java:483) ~[na:1.8.0-ea]

at ninja.params.ControllerMethodInvoker.invoke(ControllerMethodInvoker.java:55) ~[ninja-core-3.1.1.jar:na]

It doesn't always throw this exception , just about 50/50 .

Generally I first load the page , it shows ok . 

After refreshing 2 or 3 times ( or more) , the problem shows.

My action calls some DAO's get/list methods , which are not annotated anything.

The solution is simple , replace action's @UnitOfWork to @Transactional

But that's too overkill. (transaction is heavy)

I am sure the underlaying DB calls don't contain any @Transactional methods.

What may be wrong here ?

[smallufo]

It seems a common problem in guice-persist :

http://code.google.com/p/google-guice/issues/detail?id=597&can=1&q=UnitOfWork&colspec=ID%20Type%20Status%20Priority%20Milestone%20Owner%20Summary%20Component

[smallufo]

Another reference : http://barinskis.me/blog/2013/04/30/persistence-unit-of-work-pattern-in-sitebricks/

I am not sure whether unitOfWork.begin() and unitOfWork.end() are on pair.

So I modify UnitOfWorkInterceptor , adding some logging :

didWeStartWork.set(Boolean.TRUE);

System.out.println("Begin UnitOfWork");

unitOfWork.end();

System.out.println("End UnitOfWork\n");

And keep refreshing one page :

Begin UnitOfWork

2014-03-10 14:55:59,857 INFO  controllers.App - category(51) : locale = zh_TW

2014-03-10 14:55:59,886 INFO  dao.CategoryDao - get :  id=51 of object class Category

End UnitOfWork

Begin UnitOfWork

2014-03-10 14:56:01,479 INFO  controllers.App - category(51) : locale = zh_TW

2014-03-10 14:56:01,560 INFO  dao.CategoryDao - get :  id=51 of object class Category

End UnitOfWork

2014-03-10 14:56:04,401 ERROR ninja.NinjaImpl - Emitting bad request 400. Something really wrong when calling route: /category (class: class controllers.App method: public ninja.Result controllers.App.category(ninja.Context,java.lang.Long,java.lang.Integer,java.lang.Integer,java.util.Locale))

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

It seems the UnitOfWork are on pair.

But I don't know why it cannot begin another unitOfWork…

[Raphael André Bauer]

Hey smallufo,


could you provide us with a small example project where the problem
happens? This will make it a lot simpler to reproduce the issue and
check where the real problem is.

Until then the best solution is to just use @Transactional - that's
the recommended way of using guice-persist anyway - so no problem here
:)


Thanks for the report!


Raphael

> --
> You received this message because you are subscribed to the Google Groups
> "ninja-framework" group.
> To unsubscribe from this group and stop receiving emails from it, send an
> email to ninja-framewo...@googlegroups.com.
> To post to this group, send email to ninja-f...@googlegroups.com.
> To view this discussion on the web visit
> https://groups.google.com/d/msgid/ninja-framework/CAKJWkkFh8k8M2sOCQRivDBNeszXdimBq97bfHn%2B2wX7uPFjFEA%40mail.gmail.com.
>
> For more options, visit https://groups.google.com/d/optout.



--
inc: http://ars-machina.raphaelbauer.com
tech: http://ars-codia.raphaelbauer.com
web: http://raphaelbauer.com

[smallufo]

Ok .

I'll try to produce an example project in these two days.

To view this discussion on the web visit https://groups.google.com/d/msgid/ninja-framework/CACRkZ6KZGBbN4koe4Gic5O-WWBAj5FuUixq9o4RgaCp0QiRgFQ%40mail.gmail.com.

[Raphael André Bauer]

perfect!
ra

> https://groups.google.com/d/msgid/ninja-framework/CAKJWkkEvnKb4c_3RYx8%2BPFfbBkXJ5Uz0whmMq3qsuqghVw94xQ%40mail.gmail.com.

[smallufo]

Hi

This is the sample project:

https://github.com/smallufo/sample-ninja

It will fail.

My DB is MySQL, I am not sure if it has anything to do with DB or DB's driver.

To view this discussion on the web visit https://groups.google.com/d/msgid/ninja-framework/CACRkZ6%2BE%2BJ_CRVm%3DOJYnOpWHXw9URkqDai%2BMkvfn1F7bxCz0Mg%40mail.gmail.com.

[Raphael André Bauer]

Hi smallufo,


unfortunately I cannot reproduce the issue. If you want me to look
further into the issue I need two things:
- Change the DB from mysql to an embedded h2, so I can test
- A reproducible testcase. A real test that will break any build issue
with "mvn install".

If we got a failing test it'll be much simpler to say where the
problem comes from. Seems to be a strange issue indeed...

Thanks! Cheers,


Raphael

> https://groups.google.com/d/msgid/ninja-framework/CAKJWkkEZe%3DmuKzmK-NCeSZ6qsp2htgsvH2QBZpQ4ZrC-CA0a_Q%40mail.gmail.com.

[smallufo]

After I change my db from mysql to H2

The problem remains.

Just quickly refresh ( CMD-R ) the browser , it will definitely fail.

The code (just application.conf and persistence.xml) has pushed to github.

Sorry I am not sure how to write a test that simulate browser's action. I'll try it later.

At least I know it maybe not mysql or mysql-connector's problem.

To view this discussion on the web visit https://groups.google.com/d/msgid/ninja-framework/CACRkZ6%2BnGT8St9JV_Eskh-Cdk8OudNDhVTkKOpu8JpKD1zARCw%40mail.gmail.com.

[smallufo]

Hi 

This is my screen casting:

https://www.youtube.com/watch?v=O6e1efUcJFU

720 HD is available

You can see , I am not using keyboard's refresh quick key.

Even slowly click the refresh button will trigger the problem.

[Raphael André Bauer]

Hi smallufo,

that was very helpful. I was able to reproduce the issue and write a
regression test against it. The core of the problem was that it is not
allowed to nest a UnitOfWork - contrary to what guice-persist writes
on the homepage. So it seems to me that the guice-persist
documentation is misleading.

Bug and fix is described here:
https://github.com/ninjaframework/ninja/issues/157

There is now also a branch that fixes the problem. Can you test that
branch in your application and let me know if the error is gone?


Thanks for the report!

Cheers,


Raphael

> https://groups.google.com/d/msgid/ninja-framework/CAKJWkkGOwsgKrs6CcT5qeMgZGMHp_NBR6rEwsqi9v-nAMwfGpw%40mail.gmail.com.

[smallufo]

Hi

I am unfamiliar with merging your branch to mine .

Anyway , I manually modify my local 3.2.1-SNAPSHOT to fit your modifications.

https://github.com/ninjaframework/ninja/blob/c2d8e8f802cd54ecd75b7c87fc563d65b5c0c9e3/ninja-core/src/main/java/ninja/jpa/JpaModule.java

https://github.com/ninjaframework/ninja/blob/c2d8e8f802cd54ecd75b7c87fc563d65b5c0c9e3/ninja-core/src/main/java/ninja/jpa/UnitOfWorkInterceptor.java

And , wow ,  it works !

That's great !

Thanks a lot !

To view this discussion on the web visit https://groups.google.com/d/msgid/ninja-framework/CACRkZ6JJ2GBUzzcbwyJahRLV5GDtBb2YxoNUqjWQ10kzsWTeDg%40mail.gmail.com.

[Raphael André Bauer]

Nice! Good error reports makes fixing bugs easy :)

I released 3.1.2 containing the fix. Could you be so kind to check
that version with your application once it becomes available on Maven
central?


Thanks!

Raphael

> https://groups.google.com/d/msgid/ninja-framework/CAKJWkkFsXiR2cnhpGq82yLCRWvUi6%3DNYi0-EiWU74zoRUFhxRg%40mail.gmail.com.

[smallufo]

3.1.2 works flawlessly now !

Thanks.

To view this discussion on the web visit https://groups.google.com/d/msgid/ninja-framework/CACRkZ6KJqeKyoZKa076K7jkygJ0iYtGRHPTTKULypEWcqwmAHg%40mail.gmail.com.

[Raphael André Bauer]

perfect!
Thanks for the report again :)
Cheers,

Raphael

> https://groups.google.com/d/msgid/ninja-framework/CAKJWkkE9vn2TMhSbWuJrPCkUd9eT6%2BGK5G8Ofz0KSEHbruAAqQ%40mail.gmail.com.

[Taner Ozdas]

As of ninja 5.6.0 version, still same issue existed when you use @UnitOfWork, but not when @Transactional used.

[Crafton Williams]

I consistently have the same issue, using @Transactional for read queries until i have time to figure out what's going on.

[Patrick]

Same error here with Ninja version 6.0.0...

[Patrick]

Now it's 6.4.1 and same bug again... How can this be?

[Jonathan Lannoy]

Hello.

I've recently noticed the problem was still there too, so I checked for it. But it's not in our hands. It's a guice-persistence related problem. Here is a pull request on their library to avoid that exception :

https://github.com/google/guice/pull/1214

I don't understand how it has not been fixed sooner. I'm following it, as soon as it's released, I'll propose a PR for Ninja ;-)

The problem appears when you have a @UnitOfWork somewhere after an other @UnitOfWork or @Transactional. Two concrete examples :

- You have a filter using a dao and annotated

- You have an annotated controller method calling an other annotated method

Using @Transactional two times doesn't trigger the problem, this can save you for the moment.

Jonathan