Bug report: TCP deadlock between JDBC & Postgres - Mailing list pgsql-jdbc

From Royce Ausburn
Subject Bug report: TCP deadlock between JDBC & Postgres
Date
Msg-id F0785602-CD9D-4DA2-830D-5074CEE3E02E@inomial.com
Whole thread Raw
Responses Re: Bug report: TCP deadlock between JDBC & Postgres  (Dave Cramer <pg@fastcrypt.com>)
Re: Bug report: TCP deadlock between JDBC & Postgres  (Kris Jurka <books@ejurka.com>)
Re: Bug report: TCP deadlock between JDBC & Postgres  (Craig Ringer <craig@2ndquadrant.com>)
List pgsql-jdbc
Hi all,

We've managed to trip a deadlock between a JDBC client and postgres similar to what's described in github issue #194 (https://github.com/pgjdbc/pgjdbc/issues/194) and #195 (https://github.com/pgjdbc/pgjdbc/issues/195).

Here's a typical stack trace:

"http-thread-pool-17580(4)" daemon prio=10 tid=0x00007f8224059000 nid=0x66c8 runnable [0x00007f828670f000]
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketOutputStream.socketWrite0(Native Method)
        at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
        at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
        at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
        at java.io.BufferedOutputStream.write(BufferedOutputStream.java:126)
        - locked <0x00000006a40789a8> (a java.io.BufferedOutputStream)
        at java.io.FilterOutputStream.write(FilterOutputStream.java:97)
        at org.postgresql.core.PGStream.SendInteger4(PGStream.java:197)
        at org.postgresql.core.v3.QueryExecutorImpl.sendCloseStatement(QueryExecutorImpl.java:1596)
        at org.postgresql.core.v3.QueryExecutorImpl.processDeadParsedQueries(QueryExecutorImpl.java:1741)
        at org.postgresql.core.v3.QueryExecutorImpl.sendQueryPreamble(QueryExecutorImpl.java:436)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:251)
        - locked <0x00000006a4078b68> (a org.postgresql.core.v3.QueryExecutorImpl)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:570)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:420)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:305)


An strace on the postgres server process end revealed the thread was blocked sending data to the socket too.

Netstat on both ends had bytes in the send-Q

[royce@smile-test-db ~]$ netstat -an | grep 36563
tcp    57878  20016 10.20.18.204:5432       10.20.18.203:36563      ESTABLISHED
(sorry, I've lost the other end but it was nearly 64k of send-Q bytes, believe me!)


The issue emerged just after we've bumped the max JVM heap size significantly and during a heavy running migration/data transformation process with lots of jdbc queries.

The issue appears to be in how processDeadParsedQueries() works - if there're a lot of recently GC'd parsed statements then there'll be a lot of statements to close which manages to fill the send buffer on our end while the corresponding postgres process on the server end is busy filling its send buffer with responses from the close statement requests.  

We believe that reducing the heap size will mean there're more frequent GCs which will mean there'll be fewer statements to purge in any given invocation of processDeadParsedQueries() so we can hopefully work around this issue easily.

--Royce



pgsql-jdbc by date:

Previous
From: Dave Cramer
Date:
Subject: Re: Binary transfer not working
Next
From: Craig Ringer
Date:
Subject: Re: Resurrected thread: Speed improvement - Group batch Insert - Rewrite the INSERT at the driver level (using a parameter)