Обсуждение: PostgreSQL query timeout do not stop JDBC client attempt to read data from the server
PostgreSQL query timeout do not stop JDBC client attempt to read data from the server
От
Michał Niklas
Дата:
Hello, I have a problem in my multithreaded application that uses JDBC PostgreSQL driver. Sometimes it hangs for many hours with various queries to various databases. To stop such hangs I set query timeout to 10 minutes, but from my application it doesn't work, it not return after this time. jstack of such hung thread looks like: "srv_thead_160621090411" #1560 prio=5 os_prio=0 tid=0x00007f0d24001800 nid=0x150f runnable [0x00007f0c83ffd000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:170) at java.net.SocketInputStream.read(SocketInputStream.java:141) at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:143) at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:112) at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:70) at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:283) at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1799) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:200) - locked <0x00000005dc2f9f88> (a org.postgresql.core.v3.QueryExecutorImpl) at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:424) at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:161) at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:114) From server side I see that query (pid 31657) is running for > 30 seconds, but then server detects client disconnection. I think that after 10 minutes server receive "CANCEL query with PID 32657" command from JDBC driver, but this connection ended after disconnection: 2016-06-21 07:05:23.340 CEST [31657]: [1-1] postgres [unknown] 192.168.1.124(58729) dbtest %LOG: duration: 30689.838 ms execute <unnamed>: SELECT MAX(do_nr) + 1 AS numer FROM dokumenty WHERE (do_typ = 'WZ' or upper(do_typ) = upper('WZ_tmp')) AND do_dataw BETWEEN '2016-01-01 00:00:00' AND '2016-12-31 00:00:00' AND do_magazyn = 29 2016-06-21 07:05:23.340 CEST [31657]: [2-1] postgres [unknown] 192.168.1.124(58729) dbtest %LOG: could not receive data from client: Connection reset by peer 2016-06-21 07:05:23.340 CEST [31657]: [3-1] postgres [unknown] 192.168.1.124(58729) dbtest %LOG: unexpected EOF on client connection with an open transaction 2016-06-21 07:09:24.107 CEST [21]: [8151-1] %LOG: checkpoint starting: time 2016-06-21 07:14:52.620 CEST [31703]: [1-1] [unknown] [unknown] 192.168.1.124(58860) [unknown] %LOG: PID 31657 in cancel request did not match any process I think that this cancel comes from JDBC driver but I'm not sure. Strangest to me is that after 10 minutes JDBC client still wants to read data from server. It hang for a few hours until I restarted the whole service. I think there are 2 problems: 1. Something is wrong with network connections: server detects disconnection but client thinks it is still connected. 2. Query timeout do not stop JDBC attempt to read data from the server. Is there something I can do to stop my hung thread that wants to read data from the server? My environment: client: Java: 1.8.0_92 (Oracle Corporation) PostgreSQL Native Driver PostgreSQL 9.4.1208 server: PostgreSQL 9.5.3 on x86_64-pc-linux-gnu, compiled by gcc (Debian 4.9.2-10) 4.9.2, 64-bit I have already posted it on StackOverflow: http://stackoverflow.com/questions/37986081/postgresql-query-timeout-do-not-stop-jdbc-client-attempt-to-read-data-from-the-s but there is no answer :-( -- Regards, Michał Niklas
Вложения
Hi Michal,
This https://www.postgresql.org/message-id/alpine.BSO.2.03.1309261345001.26217%40ejurka.com might be related.
On 24 June 2016 at 06:17, Michał Niklas <michal.niklas@heuthes.pl> wrote:
Hello,
I have a problem in my multithreaded application that uses JDBC
PostgreSQL driver. Sometimes it hangs for many hours with various
queries to various databases. To stop such hangs I set query timeout to
10 minutes, but from my application it doesn't work, it not return after
this time.
jstack of such hung thread looks like:
"srv_thead_160621090411" #1560 prio=5 os_prio=0 tid=0x00007f0d24001800
nid=0x150f runnable [0x00007f0c83ffd000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:170)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at
org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:143)
at
org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:112)
at
org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:70)
at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:283)
at
org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1799)
at
org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:200)
- locked <0x00000005dc2f9f88> (a org.postgresql.core.v3.QueryExecutorImpl)
at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:424)
at
org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:161)
at
org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:114)
Hi Michal,
This https://www.postgresql.org/message-id/alpine.BSO.2.03.1309261345001.26217%40ejurka.com might be related.
On 24 June 2016 at 06:17, Michał Niklas <michal.niklas@heuthes.pl> wrote:
Hello,
I have a problem in my multithreaded application that uses JDBC
PostgreSQL driver. Sometimes it hangs for many hours with various
queries to various databases. To stop such hangs I set query timeout to
10 minutes, but from my application it doesn't work, it not return after
this time.
jstack of such hung thread looks like:
"srv_thead_160621090411" #1560 prio=5 os_prio=0 tid=0x00007f0d24001800
nid=0x150f runnable [0x00007f0c83ffd000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:170)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at
org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:143)
at
org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:112)
at
org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:70)
at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:283)
at
org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1799)
at
org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:200)
- locked <0x00000005dc2f9f88> (a org.postgresql.core.v3.QueryExecutorImpl)
at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:424)
at
org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:161)
at
org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:114)
Re: PostgreSQL query timeout do not stop JDBC client attempt to read data from the server
От
Vladimir Sitnikov
Дата:
Dave> This https://www.postgresql.org/message-id/alpine.BSO.2.03.1309261345001.26217%40ejurka.com might be related.
Dave, as Michael's stacktrace includes QueryExecutorImpl.processResults -> PGStream.ReceiveChar, that means the issue has nothing to do with TCP deadlock. The client somehow fails to detect socket failure => it looks like OS-TCP timeouts => it looks like a misconfigured firewall (e.g. the one that silently drops connections that are idle for more than 30 seconds).
Michael, can you please clarify if your setup involves firewalls in-between app and PG?
TCP deadlock symptom is "JDBC is trying to send more data, while the backend is trying to send response".
It is strange that in Michael's case pgjdbc thinks the connection is still alive.
We can try to protect from that kind of case by adding java-level interrupt (and/or set socket timeout to some finite value). However, adding proper interrupt logic does not seem easy, so I would still appreciate more details on the case (and/or reproducer).
Vladimir
Re: PostgreSQL query timeout do not stop JDBC client attemptto read data from the server
От
Vladimir Sitnikov
Дата:
Dave> This https://www.postgresql.org/message-id/alpine.BSO.2.03.1309261345001.26217%40ejurka.com might be related.
Dave, as Michael's stacktrace includes QueryExecutorImpl.processResults -> PGStream.ReceiveChar, that means the issue has nothing to do with TCP deadlock. The client somehow fails to detect socket failure => it looks like OS-TCP timeouts => it looks like a misconfigured firewall (e.g. the one that silently drops connections that are idle for more than 30 seconds).
Michael, can you please clarify if your setup involves firewalls in-between app and PG?
TCP deadlock symptom is "JDBC is trying to send more data, while the backend is trying to send response".
It is strange that in Michael's case pgjdbc thinks the connection is still alive.
We can try to protect from that kind of case by adding java-level interrupt (and/or set socket timeout to some finite value). However, adding proper interrupt logic does not seem easy, so I would still appreciate more details on the case (and/or reproducer).
Vladimir