Logical replication fails due to SocketException

From: Alex Maltinsky <alex(at)bgprotect(dot)com>
To: pgsql-jdbc(at)postgresql(dot)org
Subject: Logical replication fails due to SocketException
Date: 2019-05-21 13:57:19
Message-ID: CAH+ZVcYJqD5-7t5onQtDheak-KeMUdu7ouvU3FjfYRCU4jM50w@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-jdbc

Hi All

I ran into the a problem with Postgres 11 and JDBC driver 42.2.5 which
resembles a problem that was posted here before (
https://www.postgresql-archive.org/postgresql-Logical-Replication-Stream-fails-with-Database-connection-failed-when-reading-from-copy-td6036639.html)
but unfortunately the solution was never posted here.

I have a simple endless loop that follows the official replication example (
https://jdbc.postgresql.org/documentation/head/replication.html) and I
keep getting socket exceptions like these after fetching approximately 66K
rows with remarkable consistency:

Exception in thread "main" org.postgresql.util.PSQLException: Database
connection failed when reading from copy
at
org.postgresql.core.v3.QueryExecutorImpl.readFromCopy(QueryExecutorImpl.java:1037)
at
org.postgresql.core.v3.CopyDualImpl.readFromCopy(CopyDualImpl.java:41)
at
org.postgresql.core.v3.replication.V3PGReplicationStream.receiveNextData(V3PGReplicationStream.java:155)
at
org.postgresql.core.v3.replication.V3PGReplicationStream.readInternal(V3PGReplicationStream.java:124)
at
org.postgresql.core.v3.replication.V3PGReplicationStream.readPending(V3PGReplicationStream.java:78)
at com.example.main(ReplicationTest.java:48)
Caused by: java.net.SocketException: socket closed
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:171)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at
org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:140)
at
org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:109)
at
org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:191)
at org.postgresql.core.PGStream.receive(PGStream.java:462)
at org.postgresql.core.PGStream.receive(PGStream.java:446)
at
org.postgresql.core.v3.QueryExecutorImpl.processCopyResults(QueryExecutorImpl.java:1170)
at
org.postgresql.core.v3.QueryExecutorImpl.readFromCopy(QueryExecutorImpl.java:1035)
... 5 more

The database log shows "LOG: could not send data to client: Connection
reset by peer"

Wireshark shows that it was the client who suddenly sent a TCP RST to the
server and closed the connection.

Parameters: `wal_sender_timeout` is set to 60 seconds, and I'm using a
status interval of 10 seconds and TCP_KEEP_ALIVE is enabled.

The body of the Java loop looks like this:

while (true) {
ByteBuffer msg = stream.readPending();
if (msg == null) {
TimeUnit.MILLISECONDS.sleep(10L);
continue;
}

LogSequenceNumber lastReceiveLSN = stream.getLastReceiveLSN();
System.out.println((i++) + " " + lastReceiveLSN);

stream.setAppliedLSN(lastReceiveLSN);
stream.setFlushedLSN(lastReceiveLSN);
}

Curiously enough, if I change the loop to the code below, the problem
disappears:

while (true) {
ByteBuffer msg = stream.readPending();
if (msg == null) {
TimeUnit.MILLISECONDS.sleep(10L);
continue;
}

int offset = msg.arrayOffset();
byte[] source = msg.array();
int length = source.length - offset;

LogSequenceNumber lastReceiveLSN = stream.getLastReceiveLSN();
System.out.println((i++) + " " + lastReceiveLSN + " " + new
String(source, offset, length));

stream.setAppliedLSN(lastReceiveLSN);
stream.setFlushedLSN(lastReceiveLSN);
}

Any help would be appreciated

- Alex

Responses

Browse pgsql-jdbc by date

  From Date Subject
Next Message Dave Cramer 2019-05-21 18:22:00 Re: Logical replication fails due to SocketException
Previous Message Anupkumar Seth 2019-05-20 05:24:48 RE: SSL connection issue with JDBC