Thread: BUG #15598: PostgreSQL Error Code is not reported when connectionterminated due to idle-in-transaction timeout

The following bug has been logged on the website:

Bug reference:      15598
Logged by:          Marcin Barczyński
Email address:      mba.ogolny@gmail.com
PostgreSQL version: 9.6.8
Operating system:   Windows 10
Description:

Here is the output on Ubuntu:
```
postgres=# SELECT version();
                                                               version
                                                        

-------------------------------------------------------------------------------------------------------------------------------------
 PostgreSQL 9.6.9 on x86_64-pc-linux-gnu (Ubuntu 9.6.9-2.pgdg14.04+1),
compiled by gcc (Ubuntu 4.8.4-2ubuntu1~14.04.4) 4.8.4, 64-bit
(1 row)

postgres=# SET idle_in_transaction_session_timeout=500;
SET
postgres=# BEGIN;
BEGIN
postgres=# SELECT * FROM pg_class;
FATAL:  25P03: terminating connection due to idle-in-transaction timeout
LOCATION:  ProcessInterrupts, postgres.c:2996
server closed the connection unexpectedly
    This probably means the server terminated abnormally
    before or while processing the request.
The connection to the server was lost. Attempting reset: Succeeded.
```

PostgreSQL Error Code 25P03 is reported as expected.

I downloaded PostgreSQL 9.6.11 for Windows from
https://www.openscg.com/bigsql/postgresql/installers.jsp/ (referenced at
https://www.postgresql.org/download/windows/),
and the error code is not reported:
```
postgres=# SELECT version();
                                                 version
----------------------------------------------------------------------------------------------------------
 PostgreSQL 9.6.11 on x86_64-pc-mingw64, compiled by gcc.exe (Rev5, Built by
MSYS2 project) 4.9.2, 64-bit
(1 row)


postgres=# SET idle_in_transaction_session_timeout=500;
SET
postgres=# BEGIN;
BEGIN
postgres=# SELECT * FROM pg_class;
server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.
The connection to the server was lost. Attempting reset: Succeeded.
```


=?utf-8?q?PG_Bug_reporting_form?= <noreply@postgresql.org> writes:
> postgres=# SET idle_in_transaction_session_timeout=500;
> SET
> postgres=# BEGIN;
> BEGIN
> postgres=# SELECT * FROM pg_class;
> FATAL:  25P03: terminating connection due to idle-in-transaction timeout
> LOCATION:  ProcessInterrupts, postgres.c:2996
> server closed the connection unexpectedly
>     This probably means the server terminated abnormally
>     before or while processing the request.

This is not the default appearance of psql error reports.
I'd venture that you are setting VERBOSITY=verbose in your
environment, perhaps in ~/.psqlrc.  If you want the same
behavior on your Windows machine, you need to do that there too.

            regards, tom lane


On Fri, Jan 18, 2019 at 5:45 PM Tom Lane <tgl@sss.pgh.pa.us> wrote:
>
> This is not the default appearance of psql error reports.
> I'd venture that you are setting VERBOSITY=verbose in your
> environment, perhaps in ~/.psqlrc.  If you want the same
> behavior on your Windows machine, you need to do that there too.

Unfortunately, it's not the problem of verbosity.
The error code is printed properly in case of duplicate key violation. It seems that something is wrong with idle-in-transaction timeout on Windows:

postgres=# \set VERBOSITY verbose
postgres=# SET idle_in_transaction_session_timeout=500;
SET
postgres=# BEGIN;
BEGIN
postgres=# SELECT * FROM pg_class;
server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.
The connection to the server was lost. Attempting reset: Succeeded.
postgres=# CREATE TABLE demo (key BIGINT PRIMARY KEY);
CREATE TABLE
postgres=# INSERT INTO demo VALUES (1);
INSERT 0 1
postgres=# INSERT INTO demo VALUES (1);
ERROR:  23505: duplicate key value violates unique constraint "demo_pkey"
DETAIL:  Key (key)=(1) already exists.
SCHEMA NAME:  public
TABLE NAME:  demo
CONSTRAINT NAME:  demo_pkey
LOCATION:  _bt_check_unique, nbtinsert.c:433


Best regards,
Marcin
>>>>> "Marcin" == Marcin Barczyński <mba.ogolny@gmail.com> writes:

 Marcin> Unfortunately, it's not the problem of verbosity.

 Marcin> The error code is printed properly in case of duplicate key
 Marcin> violation. It seems that something is wrong with
 Marcin> idle-in-transaction timeout on Windows:

I think this is domain-dependent or platform-dependent behavior of the
result of sending data on an already-closed connection.

On Ubuntu, were you using psql -h localhost, or psql with no host
parameter (which uses local-domain sockets by default, whereas with -h
localhost it uses TCP)?

When the server forces a connection to be closed like this, it writes
the ErrorResponse packet, and then closes the connection and ends the
backend process. Since psql does not expect data at that point, the
packet will (at best) remain buffered waiting to be read.

But when you do the next query, I am fairly sure that libpq will _write_
the new query to the connection before checking for any input. If the
connection is via TCP to localhost, that write may well result in an
immediate reset of the connection (since no process is available to read
from the other end), which may cause the buffered data to be discarded
before libpq can read it, so you never see it.

This isn't something we can reasonably fix, it's inherent to how the
network protocol implementations work. Only a client program that's
prepared to check for incoming data on an idle connection (which psql
does not) has any chance of reliably getting the error packet from a
forcibly closed connection (though clients that are not local to the
database host should _usually_ get it even if they do not check).

--
Andrew (irc:RhodiumToad)