Обсуждение: BUG #17070: Sometimes copy from ingnores transaction

The following bug has been logged on the website:

Bug reference:      17070
Logged by:          Дмитрий Секретов
Email address:      d.sekretov@gmail.com
PostgreSQL version: 12.1
Operating system:   Windows Server 2016
Description:

Driver: Npgsql 4.0.9 (.net 4.7.1)

We use following construction in our code:
1. Start transaction
2. COPY FROM STDIN BINARY (table name depends on context)
3. Insert into "some_table"("some_value")
4. Commit transaction

It works fine. When something goes wrong then transaction rollbacks. 
But we found the issue. We do copy operation (step 2). When copy commands
ended the driver sends “copy done” command to postgresql backed and starts
waiting for “command complete” message and error occurs during waiting. 

2021-04-29 02:40:01,593 ERROR Exception while reading from stream --->
System.IO.IOException: Unable to read data from the transport connection: A
connection attempt failed because the connected party did not properly
respond after a period of time, or established connection failed because
connected host has failed to respond. 

In a 160 seconds postgresql reported in logs

2021-04-29 02:42:41 database LOG:  duration: 202590.129 ms  statement: COPY
"principal_reference" (id,"some_payload") FROM STDIN BINARY;
2021-04-29 02:42:41 database LOG:  could not receive data from client: An
established connection was aborted by the software in your host machine.

In our application code we retry operation, if something goes wrong. And
when we start retrying we've got an exception
2021-04-29 02:42:41 database ERROR:  duplicate key value violates unique
constraint "PK_principal_reference_id"

We didn't commit transaction. But copy done successfully and there is no row
inserted at step 3. 
Is there a workaround? Like a copy into temp table and then insert from temp
table?

On Wed, Jun 23, 2021 at 07:02:18AM +0000, PG Bug reporting form wrote:
> The following bug has been logged on the website:
> 
> Bug reference:      17070
> Logged by:          Дмитрий Секретов
> Email address:      d.sekretov@gmail.com
> PostgreSQL version: 12.1
> Operating system:   Windows Server 2016
> Description:        
> 
> Driver: Npgsql 4.0.9 (.net 4.7.1)
> 
> We use following construction in our code:
> 1. Start transaction
> 2. COPY FROM STDIN BINARY (table name depends on context)
> 3. Insert into "some_table"("some_value")
> 4. Commit transaction
> 
> It works fine. When something goes wrong then transaction rollbacks. 
> But we found the issue. We do copy operation (step 2). When copy commands
> ended the driver sends “copy done” command to postgresql backed and starts
> waiting for “command complete” message and error occurs during waiting. 
> 
> 2021-04-29 02:40:01,593 ERROR Exception while reading from stream --->
> System.IO.IOException: Unable to read data from the transport connection: A
> connection attempt failed because the connected party did not properly
> respond after a period of time, or established connection failed because
> connected host has failed to respond. 
> 
> In a 160 seconds postgresql reported in logs
> 
> 2021-04-29 02:42:41 database LOG:  duration: 202590.129 ms  statement: COPY
> "principal_reference" (id,"some_payload") FROM STDIN BINARY;
> 2021-04-29 02:42:41 database LOG:  could not receive data from client: An
> established connection was aborted by the software in your host machine.
> 
> In our application code we retry operation, if something goes wrong. And
> when we start retrying we've got an exception
> 2021-04-29 02:42:41 database ERROR:  duplicate key value violates unique
> constraint "PK_principal_reference_id"
> 
> We didn't commit transaction. But copy done successfully and there is no row
> inserted at step 3. 

Most likely, (1) never happened, so your application was actually running (2)
as an implied transaction that did commit.  One way to confirm this is to set
log_statement=all and look for the BEGIN (or START TRANSACTION) command in the
logs.  What sequence of commands does the server log show from the session
that experiences the problem?

> Is there a workaround? Like a copy into temp table and then insert from temp
> table?

There probably would be a workaround, but if COPY results are visible after a
transaction rollback, that would be a bug.

On Fri, Sep 17, 2021 at 02:13:43PM +0300, Дмитрий Секретов wrote:
> It happens very rarely and it happens in production (2-3 times a year), i
> can't log all. I look into code and we always start transaction. We have
> tests - rollback works fine. But it happened.

A missing BEGIN is something like one hundred times as likely as a PostgreSQL
bug here.  I understand you can't set log_statement=all in production.  If you
do a non-production test with log_statement=all, you may be able to locate the
missing BEGIN.