commit not doing a commit?

classic Classic list List threaded Threaded
2 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

commit not doing a commit?

tbee
I've got a bit of a strange situation here. I'm using Bitronix to have an Eclipselink based business model and Activiti workflow work in unison. The problem is that one Activiti SQL statement blocks and times out. Below is all interaction with the database with the final statement blocking.

 169: [EL Finer]: 2012-09-20 14:08:17.962--ClientSession(5578877)--Thread(Thread[main,5,main])--TX beginTransaction, status=STATUS_ACTIVE
 306: 2012-09-20 14:08:20,448 DEBUG #5958562[C22645161] activiti: execute: update ACT_GE_PROPERTY     ...
 334: 2012-09-20 14:08:20,495 DEBUG #10522721[C5094311] activiti: execute: insert into ACT_RU_EXECUTION ...
 360: 2012-09-20 14:08:20,495 DEBUG #25022548[C5094311] activiti: execute: insert into ACT_HI_PROCINST ...
 384: 2012-09-20 14:08:20,511 DEBUG #13502571[C5094311] activiti: execute: insert into ACT_HI_ACTINST ...
 408: 2012-09-20 14:08:20,526 DEBUG #25489800[C5094311] activiti: execute: insert into ACT_RU_VARIABLE ...
 432: 2012-09-20 14:08:20,542 DEBUG #28968689[C5094311] activiti: execute: insert into ACT_RU_VARIABLE ...
 456: 2012-09-20 14:08:20,542 DEBUG #9486511[C5094311] activiti: execute: insert into ACT_HI_ACTINST ...
 486: 2012-09-20 14:08:20,557 DEBUG #4047039[C5094311] activiti: execute: insert into ACT_RU_TASK ...
 520: 2012-09-20 14:08:20,573 DEBUG #2157445[C5094311] activiti: execute: insert into ACT_HI_TASKINST ...
 534: 2012-09-20 14:08:20,589 DEBUG #22864626[C5094311] activiti: execute: insert into ACT_RU_IDENTITYLINK ...
 559: [EL Finer]: 2012-09-20 14:08:20.604--UnitOfWork(30281720)--Thread(Thread[main,5,main])--begin unit of work commit
 571: 2012-09-20 14:08:20,604 DEBUG #11026351[C21771814] frozn: executeUpdate: UPDATE whitelabel ...
 586: 2012-09-20 14:08:20,620 DEBUG #19807584[C21771814] frozn: executeUpdate: UPDATE application ...
 671: 2012-09-20 14:08:20,667 DEBUG #1945002[C21771814] frozn: executeUpdate: INSERT INTO application ...
 674: [EL Finer]: 2012-09-20 14:08:20.714--UnitOfWork(30281720)--Thread(Thread[main,5,main])--TX afterCompletion callback, status=COMMITTED
 676: ---------------------------
 677: [EL Finer]: 2012-09-20 14:08:20.729--ClientSession(5578877)--Thread(Thread[main,5,main])--TX beginTransaction, status=STATUS_ACTIVE
 741: 2012-09-20 14:08:20,808 DEBUG #17985579[C5094311] activiti: execute: update ACT_RU_TASK ...
 769: 2012-09-20 14:08:20,823 DEBUG #32139235[C5094311] activiti: execute: update ACT_HI_TASKINST ...
 781: 2012-09-20 14:08:20,823 DEBUG #28336320[C5094311] activiti: execute: update ACT_HI_ACTINST ...
 830: 2012-09-20 14:08:20,870 DEBUG  877: 2012-09-20 14:08:20,901 DEBUG #28860947[C22645161] activiti: execute: insert into ACT_RU_VARIABLE ...
 913: 2012-09-20 14:08:20,917 DEBUG #9528986[C5094311] activiti: execute: insert into ACT_RU_EXECUTION ...
 937: 2012-09-20 14:08:20,933 DEBUG #33054865[C5094311] activiti: execute: insert into ACT_HI_ACTINST ...
 961: 2012-09-20 14:08:20,948 DEBUG #21289936[C5094311] activiti: execute: insert into ACT_HI_ACTINST ...
 991: 2012-09-20 14:08:20,980 DEBUG #23935686[C5094311] activiti: execute: insert into ACT_RU_TASK ...
1025: 2012-09-20 14:08:20,995 DEBUG #31851612[C5094311] activiti: execute: insert into ACT_HI_TASKINST ...


The ID between square brackets denotes the actual JDBC connection being used. The prefix "activiti:" or "frozn:" denotes which data source is being used. The dashes are a Bitronix commit.

I cannot see how that last statement would block, since all interaction on that table is done through the same connection. However, prefix 408, 432 and 877 accesses the same table through different connections. That could cause a conflict, if there wasn't a commit in between. But after commenting out the line causing 877 the lock does not occur.

So I must suspect that the commit did not actually commit? Can that be the case?

This suspicion is further enhanced because even though my unit test is full of commits, not all are written to the database. Can begins and commit not be changed (begin, commit, begin, commit) on the same transaction manager?
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: commit not doing a commit?

Ludovic Orban-2
Sorry for the delay answering your question.

There is no way a commit can uncommitted data behind itself, unless the JDBC driver or the database is buggy which is very unlikely.

If you suspect such behavior, you should look for integration and/or configuration problems in or between BTM, EclipseLink, Activiti.

Enabling BTM debug logs on bitronix.tm.BitronixTransactionManager should tell you exactly when BTM receives its calls to begin and commit the transactions. You should also make sure that EclipseLink is aware of the JTA environment surrounding it, have a look at this thread to figure out what that requires: http://old.nabble.com/Tomcat-7%2C-Bitronix%2C-Spring-JTA%2C-JPA-td34218255.html

Activiti will probably need some setup as well, but I'm not sure what should be done as I'm not familiar with that product. Finally, make sure that you and EclipseLink are only using the BTM connection pool, as using any other or would completely bypass the BTM transaction management.

I hope this helps a bit.

--
Ludovic



On Thu, Sep 20, 2012 at 3:58 PM, tbee <[hidden email]> wrote:

I've got a bit of a strange situation here. I'm using Bitronix to have an
Eclipselink based business model and Activiti workflow work in unison. The
problem is that one Activiti SQL statement blocks and times out. Below is
all interaction with the database with the final statement blocking.

 169: [EL Finer]: 2012-09-20
14:08:17.962--ClientSession(5578877)--Thread(Thread[main,5,main])--TX
beginTransaction, status=STATUS_ACTIVE
 306: 2012-09-20 14:08:20,448 DEBUG #5958562[C22645161] activiti: execute:
update ACT_GE_PROPERTY     ...
 334: 2012-09-20 14:08:20,495 DEBUG #10522721[C5094311] activiti: execute:
insert into ACT_RU_EXECUTION ...
 360: 2012-09-20 14:08:20,495 DEBUG #25022548[C5094311] activiti: execute:
insert into ACT_HI_PROCINST ...
 384: 2012-09-20 14:08:20,511 DEBUG #13502571[C5094311] activiti: execute:
insert into ACT_HI_ACTINST ...
 408: 2012-09-20 14:08:20,526 DEBUG #25489800[C5094311] activiti: execute:
insert into ACT_RU_VARIABLE ...
 432: 2012-09-20 14:08:20,542 DEBUG #28968689[C5094311] activiti: execute:
insert into ACT_RU_VARIABLE ...
 456: 2012-09-20 14:08:20,542 DEBUG #9486511[C5094311] activiti: execute:
insert into ACT_HI_ACTINST ...
 486: 2012-09-20 14:08:20,557 DEBUG #4047039[C5094311] activiti: execute:
insert into ACT_RU_TASK ...
 520: 2012-09-20 14:08:20,573 DEBUG #2157445[C5094311] activiti: execute:
insert into ACT_HI_TASKINST ...
 534: 2012-09-20 14:08:20,589 DEBUG #22864626[C5094311] activiti: execute:
insert into ACT_RU_IDENTITYLINK ...
 559: [EL Finer]: 2012-09-20
14:08:20.604--UnitOfWork(30281720)--Thread(Thread[main,5,main])--begin unit
of work commit
 571: 2012-09-20 14:08:20,604 DEBUG #11026351[C21771814] frozn:
executeUpdate: UPDATE whitelabel ...
 586: 2012-09-20 14:08:20,620 DEBUG #19807584[C21771814] frozn:
executeUpdate: UPDATE application ...
 671: 2012-09-20 14:08:20,667 DEBUG #1945002[C21771814] frozn:
executeUpdate: INSERT INTO application ...
 674: [EL Finer]: 2012-09-20
14:08:20.714--UnitOfWork(30281720)--Thread(Thread[main,5,main])--TX
afterCompletion callback, status=COMMITTED
 676: ---------------------------
 677: [EL Finer]: 2012-09-20
14:08:20.729--ClientSession(5578877)--Thread(Thread[main,5,main])--TX
beginTransaction, status=STATUS_ACTIVE
 741: 2012-09-20 14:08:20,808 DEBUG #17985579[C5094311] activiti: execute:
update ACT_RU_TASK ...
 769: 2012-09-20 14:08:20,823 DEBUG #32139235[C5094311] activiti: execute:
update ACT_HI_TASKINST ...
 781: 2012-09-20 14:08:20,823 DEBUG #28336320[C5094311] activiti: execute:
update ACT_HI_ACTINST ...
 830: 2012-09-20 14:08:20,870 DEBUG  877: 2012-09-20 14:08:20,901 DEBUG
#28860947[C22645161] activiti: execute: insert into ACT_RU_VARIABLE ...
 913: 2012-09-20 14:08:20,917 DEBUG #9528986[C5094311] activiti: execute:
insert into ACT_RU_EXECUTION ...
 937: 2012-09-20 14:08:20,933 DEBUG #33054865[C5094311] activiti: execute:
insert into ACT_HI_ACTINST ...
 961: 2012-09-20 14:08:20,948 DEBUG #21289936[C5094311] activiti: execute:
insert into ACT_HI_ACTINST ...
 991: 2012-09-20 14:08:20,980 DEBUG #23935686[C5094311] activiti: execute:
insert into ACT_RU_TASK ...
1025: 2012-09-20 14:08:20,995 DEBUG #31851612[C5094311] activiti: execute:
insert into ACT_HI_TASKINST ...


The ID between square brackets denotes the actual JDBC connection being
used. The prefix "activiti:" or "frozn:" denotes which data source is being
used. The dashes are a Bitronix commit.

I cannot see how that last statement would block, since all interaction on
that table is done through the same connection. However, prefix 408, 432 and
877 accesses the same table through different connections. That could cause
a conflict, if there wasn't a commit in between. But after commenting out
the line causing 877 the lock does not occur.

So I must suspect that the commit did not actually commit? Can that be the
case?

This suspicion is further enhanced because even though my unit test is full
of commits, not all are written to the database. Can begins and commit not
be changed (begin, commit, begin, commit) on the same transaction manager?

--
View this message in context: http://old.nabble.com/commit-not-doing-a-commit--tp34457533p34457533.html
Sent from the Bitronix Transaction Manager mailing list archive at Nabble.com.


---------------------------------------------------------------------
To unsubscribe from this list, please visit:

    http://xircles.codehaus.org/manage_email



Loading...