Thread: locking problem in jdbc driver?

locking problem in jdbc driver?

From

Sherif Kottapurath

Date:

30 December 2009, 15:31:21

I am seeing the following problem, where a thread holding a java lock
seems to be blocking another query. I suspect the the thread holding the java lock
may be waiting for a DB lock to be freed by the second one. I am pasting the
relevant parts of the java stack trace. All threads shown here are operating on
the same table, and they are all parts of transactions involving multiple tables.
deadlock detection is set for 1 sec and no dedlocks are reported by postgres.

"http-192.168.0.22-8080-6" daemon prio=10 tid=0x083bcc00 nid=0x2fc4 waiting for monitor entry [0x8c9fd000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:169)
        - waiting to lock <0x959ebed0> (a org.postgresql.core.v3.QueryExecutorImpl)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:452)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:351)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:255)
        at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:76)
        at sun.reflect.GeneratedMethodAccessor61.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        ...

"http-192.168.0.22-8080-3" prio=10 tid=0x8ea6e000 nid=0x2f3e runnable [0x8c9ad000]
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:129)
        at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:135)
        at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:104)
        at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:73)
        at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:255)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1165)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:191)
        - locked <0x959ebed0> (a org.postgresql.core.v3.QueryExecutorImpl)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:452)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:351)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:305)
        at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:105)
        ...

"http-192.168.0.22-8080-5" daemon prio=10 tid=0x0900c000 nid=0x2f53 runnable [0x8c56d000]
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:129)
        at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:135)
        at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:104)
        at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:73)
        at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:255)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1165)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:191)
        - locked <0x959e0800> (a org.postgresql.core.v3.QueryExecutorImpl)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:452)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:351)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:305)
        at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:105)
        at sun.reflect.GeneratedMethodAccessor94.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        ...
"http-192.168.0.22-8080-4" daemon prio=10 tid=0x08eae000 nid=0x2f4f runnable [0x8c5be000]
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:129)
        at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:135)
        at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:104)
        at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:73)
        at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:255)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1165)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:191)
        - locked <0x98004510> (a org.postgresql.core.v3.QueryExecutorImpl)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:452)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:351)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:305)
        at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:105)
        at sun.reflect.GeneratedMethodAccessor94.invoke(Unknown Source)
        ...

Sherif

Re: locking problem in jdbc driver?

From

Richard Broersma

Date:

30 December 2009, 15:47:03

On Wed, Dec 30, 2009 at 8:29 AM, Sherif Kottapurath <sherifkm@gmail.com> wrote:

> All threads shown here are operating on
> the same table, and they are all parts of transactions involving multiple tables.
> deadlock detection is set for 1 sec and no dedlocks are reported by postgres.

From my experience, PostgreSQL doesn't report deadlocks.  This is true
when purposely creating a dead-lock situation using two instances of
psql.  However, unless you've set your transaction isolation level to
SERIALIZABLE ( the default isolation level is READ COMMITED), you will
not be getting deadlocks from PostgreSQL.

http://www.postgresql.org/docs/8.4/interactive/transaction-iso.html#XACT-SERIALIZABLE
http://www.postgresql.org/docs/8.4/interactive/transaction-iso.html#XACT-READ-COMMITTED

Also, IIRC the PostgreSQL JDBC driver only allows a single thread to
access a connection object at a time.

http://jdbc.postgresql.org/documentation/84/thread.html

Could this be causing your problem?

--
Regards,
Richard Broersma Jr.

Re: locking problem in jdbc driver?

From

Craig Ringer

Date:

31 December 2009, 00:02:14

On 31/12/2009 12:46 AM, Richard Broersma wrote:
> On Wed, Dec 30, 2009 at 8:29 AM, Sherif Kottapurath<sherifkm@gmail.com>  wrote:
>
>> All threads shown here are operating on
>> the same table, and they are all parts of transactions involving multiple tables.
>> deadlock detection is set for 1 sec and no dedlocks are reported by postgres.
>
>  From my experience, PostgreSQL doesn't report deadlocks.

It should, at least with default settings. Failure to do so would, I
expect, be considered a bug. How, exactly, are you creating a deadlock
situation for your testing?

 > However, unless you've set your transaction isolation level to
> SERIALIZABLE ( the default isolation level is READ COMMITED), you will
> not be getting deadlocks from PostgreSQL.

Sure you will. In READ COMMITTED:

CREATE TABLE a ( );
CREATE TABLE b ( );

T1:   LOCK TABLE a;
T2:   LOCK TABLE b;
T2:   LOCK TABLE a;
T1:   LOCK TABLE b;

then one of the transactions will be aborted with:

ERROR:  deadlock detected
DETAIL:  Process 13674 waits for AccessExclusiveLock on relation 57791
of database 57071; blocked by process 13672.
Process 13672 waits for AccessExclusiveLock on relation 57788 of
database 57071; blocked by process 13674.
HINT:  See server log for query details.

What *doesn't* happen in read committed isolation is serialization failures.

> Also, IIRC the PostgreSQL JDBC driver only allows a single thread to
> access a connection object at a time.

Yep. It's thread safe, but a given connection can only be doing one
thing at a time, so other Java threads will wait for access to the
connection.

--
Craig Ringer

Re: locking problem in jdbc driver?

From

Craig Ringer

Date:

31 December 2009, 00:07:27

On 31/12/2009 12:29 AM, Sherif Kottapurath wrote:
> I am seeing the following problem, where a thread holding a java  lock
> seems to be blocking another query. I suspect the the thread holding the
> java lock
> may be waiting for a DB lock to be freed by the second one. I am pasting the
> relevant parts of the java stack trace. All threads shown here are
> operating on
> the same table, and they are all parts of transactions involving
> multiple tables.

It looks like your threads may all be trying to use the same connection.

The PgJDBC documentation states: "If a thread attempts to use the
connection while another one is using it, it will wait until the other
thread has finished its current operation. If the operation is a regular
SQL  statement, then the operation consists of sending the statement and
retrieving any ResultSet (in full)."

The lock your thread is waiting on is a lock that controls access to the
PostgreSQL connection object so that only one thread may do work with it
at a time. If your threads are deadlocking, it's probably because one
thread is waiting for another to do work that it cannot do until the
first thread releases the connection. Perhaps you forgot to close a
statement somewhere?

> deadlock detection is set for 1 sec and no dedlocks are reported by
> postgres.

PostgreSQL will detect deadlocks where two connections in PostgreSQL are
each waiting for locks the other connection holds. You're only using one
connection, and your issue is with Java locking, so PostgreSQL knows
nothing about it.

--
Craig Ringer

Re: locking problem in jdbc driver?

From

Sherif Kottapurath

Date:

31 December 2009, 05:28:34

On Thu, Dec 31, 2009 at 6:37 AM, Craig Ringer <craig@postnewspapers.com.au> wrote:

On 31/12/2009 12:29 AM, Sherif Kottapurath wrote:
I am seeing the following problem, where a thread holding a java lock
seems to be blocking another query. I suspect the the thread holding the
java lock
may be waiting for a DB lock to be freed by the second one. I am pasting the
relevant parts of the java stack trace. All threads shown here are
operating on
the same table, and they are all parts of transactions involving
multiple tables.

It looks like your threads may all be trying to use the same connection.

The PgJDBC documentation states: "If a thread attempts to use the connection while another one is using it, it will wait until the other thread has finished its current operation. If the operation is a regular SQL statement, then the operation consists of sending the statement and retrieving any ResultSet (in full)."

The lock your thread is waiting on is a lock that controls access to the PostgreSQL connection object so that only one thread may do work with it at a time.

Thanks Craig. This has set us off in the right direction. There is some code which passes transactions (and related connection)
around threads, and that must be the culprit. Should be able to report back within a day whether that was indeed the culprit.

If your threads are deadlocking, it's probably because one thread is waiting for another to do work that it cannot do until the first thread releases the connection. Perhaps you forgot to close a statement somewhere?

deadlock detection is set for 1 sec and no dedlocks are reported by
postgres.

PostgreSQL will detect deadlocks where two connections in PostgreSQL are each waiting for locks the other connection holds. You're only using one connection, and your issue is with Java locking, so PostgreSQL knows nothing about it.

We are using multiple connections, but apparently, sometimes 2 threads are trying to use the same connection
and one of these threads is also holding another incomplete transaction.

Thanks a lot.

Sherif

--
Craig Ringer