Message-ID: <gh-pgjdbc-pgjdbc-194-c486722486@github.com>
From: "turbanoff (@turbanoff)" <noreply+turbanoff@github.com>
To: "pgjdbc/pgjdbc" <noreply+pgjdbc-pgjdbc@github.com>
Date: Thu, 25 Apr 2019 15:29:41 +0000
Subject: Re: [pgjdbc/pgjdbc] issue #194: PgJDBC can experience client/server deadlocks during batch execution
In-Reply-To: <gh-pgjdbc-pgjdbc-194@github.com>
References: <gh-pgjdbc-pgjdbc-194@github.com>
List-Id: <gh-pgjdbc-pgjdbc.github.com>
X-GitHub-Author-Login: turbanoff
X-GitHub-Comment-Id: 486722486
X-GitHub-Comment-Type: issue_comment
X-GitHub-Edited-At: 2019-04-25T19:50:32Z
X-GitHub-Issue: 194
X-GitHub-Repo: pgjdbc/pgjdbc
X-GitHub-Type: comment
X-GitHub-Url: https://github.com/pgjdbc/pgjdbc/issues/194#issuecomment-486722486
Content-Type: text/plain; charset=utf-8

Had this problem too on latest version of driver 42.2.5. Thread stuck with this stack trace
```
java.lang.Thread.State: RUNNABLE
	at java.net.SocketOutputStream.socketWrite0(Native Method)
	at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109)
	at java.net.SocketOutputStream.write(SocketOutputStream.java:153)
	at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
	at java.io.BufferedOutputStream.write(BufferedOutputStream.java:126)
	- locked <0x00000006c09dd2d8> (a java.io.BufferedOutputStream)
	at java.io.FilterOutputStream.write(FilterOutputStream.java:97)
	at org.postgresql.core.PGStream.sendInteger4(PGStream.java:226)
	at org.postgresql.core.v3.QueryExecutorImpl.sendBind(QueryExecutorImpl.java:1559)
	at org.postgresql.core.v3.QueryExecutorImpl.sendOneQuery(QueryExecutorImpl.java:1805)
	at org.postgresql.core.v3.QueryExecutorImpl.sendQuery(QueryExecutorImpl.java:1328)
	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:467)
	- locked <0x00000006c09daf40> (a org.postgresql.core.v3.QueryExecutorImpl)
	at org.postgresql.jdbc.PgStatement.executeBatch(PgStatement.java:840)
	at org.postgresql.jdbc.PgPreparedStatement.executeBatch(PgPreparedStatement.java:1538)
	at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:2437)
```

Native stack trace:
```
Thread 79 (Thread 0x7fb146ff1700 (LWP 7547)):
#0  0x00007fb227d7acfb in send () from /lib64/libpthread.so.0
#1  0x00007fb200de919e in NET_Send () from /opt/java/jdk1.8.0_40/jre/lib/amd64/libnet.so
#2  0x00007fb200de8d5a in Java_java_net_SocketOutputStream_socketWrite0 () from /opt/java/jdk1.8.0_40/jre/lib/amd64/libnet.so
#3  0x00007fb21190661a in ?? ()
#4  0x00000006c09db230 in ?? ()
#5  0x00000006c09db180 in ?? ()
#6  0x00000006c09dd2f0 in ?? ()
#7  0x00000006c09dd2d8 in ?? ()
#8  0x0000000000000b8b in ?? ()
#9  0x0000000000000000 in ?? ()
```

One of TCP connections (used by stuck thread) has big `Recv-Q` and `Send-Q`
```
$ netstat -atpW | grep 3498 | grep postgre
Proto Recv-Q Send-Q Local Address    Foreign Address        State       PID/Program name
[otaprodqa@otaprodqa] [Wed Apr 24, 20:30:59] [2034][~ ]$ netstat -atpW | grep 3498 | grep postgre
Proto Recv-Q Send-Q Local Address                      Foreign Address                     State       PID/Program name
tcp6       0      0 somelonghostname.mycompa.com:39994 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:39954 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:39992 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:39998 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:39968 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:38214 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:40002 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:40018 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:39964 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:39956 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:39970 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:39986 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:39972 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:39990 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:39978 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:40010 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:40008 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:39996 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6  149016  53616 somelonghostname.mycompa.com:40012 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:39980 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:39982 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
tcp6       0      0 somelonghostname.mycompa.com:39966 myaqadb.in.somesompany.com:postgres ESTABLISHED 3498/java
```
Are there any known workarounds? May be setting query timeout can help?