Write lock is not released

[metastaz]

Hi all,

we have JBoss 4.0.2 , JBossCache 1.2.2 and Hibernate 3.1.
Isolation level = repeatable read

Ocasionay we observe a following in logs:
1) thread x starts a transaction and obtains a write lock on resource A
2) ~30 mins go by
3) transaction in thread x fails to obtain a _read_ lock on resource A, since
write lock is already held by thread x:

[ReportDataTaskRunner-20521017-1] - Transaction failed due to exception
org.hibernate.cache.CacheException: org.jboss.cache.lock.TimeoutException: read lock for Attribute#4558 could not be acquired by <zzz:4256>:162303 after 15000 ms. Locks: Read lock owners: []
Write lock owner: Thread[ReportDataTaskRunner-20521017-1,5,jboss]
, lock info: write owner=Thread[ReportDataTaskRunner-20521017-1,5,jboss] (activeReaders=0, activeWriter=Thread[ReportDataTaskRunner-20521017-1,5,jboss], waitingReaders=0, waitingWriters=0, waitingUpgrader=0)

This lock stays forever.

I'd appreciate any hints on this.

Thanks in advance,
Stas.

[genman]

What's the write thread doing? (Can you get a stack trace of your application at this time?)

[metastaz]

"genman" wrote:
What's the write thread doing? (Can you get a stack trace of your application at this time?)

Yep that's a good idea. However I do not have exact steps to reproduce this issue, and we observe it only ocassionaly in production. I'll try to reproduce it and get the stack trace.

Thank you,
Stas.

[metastaz]

"genman" wrote:
What's the write thread doing? (Can you get a stack trace of your application at this time?)

Meanwhile, any other ideas?

[manik]

It looks like the current WL holder and the RL requestor are not the same:

... could not be acquired by <zzz:4256>:162303 ...

and

... Write lock owner: Thread[ReportDataTaskRunner-20521017-1,5,jboss] ...

A thread dump would be very helpful.

In addition, what transaction manager (if any) have you configured for JBoss Cache (the TransactionManagerLookup attribute in your JBoss Cache cfg xml)?

[metastaz]

It looks like the current WL holder and the RL requestor are not the same:

... could not be acquired by <zzz:4256>:162303 ...

and

... Write lock owner: Thread[ReportDataTaskRunner-20521017-1,5,jboss] ...

A thread dump would be very helpful.

In addition, what transaction manager (if any) have you configured for JBoss Cache (the TransactionManagerLookup attribute in your JBoss Cache cfg xml)?

Oh, I see first time thread acquired WL without GlobalTransaction but then it tries to get a RL having one.

As for TransactionManagerLookup - we have TransactionManagerLookupClass attribute set to org.jboss.cache.JBossTransactionManagerLookup

Thank you,
Stas.

[vitamin-c]

It looks like the current WL holder and the RL requestor are not the same:

... could not be acquired by <zzz:4256>:162303 ...

and

... Write lock owner: Thread[ReportDataTaskRunner-20521017-1,5,jboss] ...

Is it OK that RL requestor thread uses a GlobalTransaction, whereas WL owner thread doesn't?

Here's the code, where a GlobalTransaction is assigned to a thread requesting a lock (either RL or WL):

package org.jboss.cache.interceptors;
...
public class LockInterceptor extends Interceptor {
...
 public Object invoke(MethodCall m) throws Throwable {
...
 GlobalTransaction gtx=null;
...
 if(tx_mgr != null && (tx=tx_mgr.getTransaction()) != null && isValid(tx)) { // ACTIVE or PREPARING
 if(!transactions.contains(tx)) {
 gtx=cache.getCurrentTransaction(tx);
 if(gtx == null)
 throw new Exception("failed to get global transaction");
...
 else {
 gtx=cache.getTransactionTable().get(tx);
 }
...

Assuming that transaction manager presents, it is still unclear will a thread receive a non-null gtx, since cache.getTransactionTable().get(tx) doesn't check for null return value. According to metastaz's observations a thread may or may not receive a gtx, which looks like a bug, doesn't it?

Thanks,
Alexey