Re: Bug report: TCP deadlock between JDBC & Postgres

Royce,

What version of the driver are you using ? It appears that Craig did commit
some code for the two issues you referenced.

Dave Cramer

dave.cramer(at)credativ(dot)ca
http://www.credativ.ca

On 8 April 2015 at 22:30, Royce Ausburn <royce(at)inomial(dot)com> wrote:

> 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(at)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
>
>
>
>