[Mulgara-general] MulgaraTransactionException

[Life is hard, and then you die]

  Hi Eddie,

On Wed, Jul 16, 2008 at 11:46:04PM +0800, Edwin Shin wrote:
> On 07/16/2008 07:18 PM, Life is hard, and then you die is rumored to 
> have said:
> >On Tue, Jul 15, 2008 at 10:35:56PM +0800, Edwin Shin wrote:
> >>I've been having some trouble running down an error our users have been 
> >>hitting with Mulgara. Unfortunately, while I can reproduce the error 
> >>quite regularly when inserting enough triples, I can't reproduce it when 
> >>I run it through a debugger, nor when I write a very simple unit test. 
> >>It seems to require at least some tens of thousands of triples to 
> >>provoke with any regularity, however.
[snip]
> >I have just recently fixed a few synchronization problems - these
> >fixes are currenlty sitting in the mgr-121-lockrecovery branch (soon
> >to be merged into trunk). If you can try that out and let me know,
> >that would be great.
> >
> >However, something's still odd - do you have the logs at level info?
> >Those wouuld help in tracing back how things got here. (debug would be
> >even more helpful) You may want to limit the logging to the following
> >classes in order to keep the logs manageable:
> >
> >  org.mulgara.resolver.MulgaraInternalTransaction
> >  org.mulgara.resolver.MulgaraInternalTransactionFactory
> >  org.mulgara.resolver.MulgaraTransactionFactory
> >  org.mulgara.resolver.MulgaraTransactionManager
> >  org.mulgara.resolver.DatabaseSession
> 
> Switching to the new branch seems yields different errors, but at least 
> allows the unit test to complete. I'm attaching the log output (DEBUG 
> for just the classes you listed above).

Can you clarify what errors you're getting?

In any case, you're doing something that isn't completely kosher. What
I see in the logs is the following (near the end):

  DEBUG 2008-07-16 23:39:02.583 [Thread-4] (DatabaseSession) Modifying (ins:true) : rmi://localhost/fedora#ri
  DEBUG 2008-07-16 23:39:02.584 [Thread-4] (MulgaraTransactionManager) Obtaining write lock
  ...
  INFO 2008-07-16 23:39:02.584 [Thread-4] (MulgaraInternalTransaction) Executing Operation: 2791549, state=CONSTRUCTEDUNREF, inuse=0, using=0
  ...
  INFO 2008-07-16 23:39:02.585 [Thread-4] (MulgaraInternalTransactionFactory) Beginning Transaction
  DEBUG 2008-07-16 23:39:03.333 [main] (DatabaseSession) Closing session
  DEBUG 2008-07-16 23:39:03.333 [main] (MulgaraTransactionFactory) Cleaning up any stale transactions on session close
  DEBUG 2008-07-16 23:39:03.334 [main] (MulgaraTransactionFactory) Session holds write-lock
  DEBUG 2008-07-16 23:39:03.334 [main] (MulgaraTransactionManager) Releasing writelock

The fact that the session being closed is holding the write lock
indicates this is the same session as was used just previously in
Thread-4, and in which presumably the insert is still in progress.

I.e. it looks like you are closing down a session that is still in
active use (note there's not "Executed Operation" for Thread-4 here).
This is not allowed: a session may only be used by one thread at a
time and if used by multiple threads (serially) must have appropriate
synchronization (memory barriers) between invocations.

However, having said that, there seem to be two issues on the mulgara
side I see in this log that I'm investigating.


  Cheers,

  Ronald