Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Connection in poll broken once PGCopyInputStream fails #3163

Open
PiotrDuz opened this issue Mar 13, 2024 · 10 comments
Open

Connection in poll broken once PGCopyInputStream fails #3163

PiotrDuz opened this issue Mar 13, 2024 · 10 comments

Comments

@PiotrDuz
Copy link

PiotrDuz commented Mar 13, 2024

Describe the issue
We have noticed that when PGCopyInputStream fails during input stream reading, the connection even when being handled properly (within try block) will be broken for future calls to database when reused from the connection pool.

For example, if we fetch some data and copy fails during fetching, later select statement gets the residuals of previous COPY, even when the connection has been properly closed() (returned to the pool).

Please refer tot he example, as we are closing not only the connection but the PGCopyInputStream itself. The reproductible example is the simplest I could get, so error with unexpected data i not shown, rather the select just fails with no data.

Driver Version?
42.6.0

Java Version?
21

OS Version?
MacOS Sonoma 14.2.1 (23C71)

PostgreSQL Version?
DB version 14

To Reproduce
The repo contains the project that runs testcontainers and execute the tests:
https://github.com/PiotrDuz/pgcopy-exception-bug

We have the test when we dont throw an exception (error=false) and we don't evict connection (evict=false).
Second example, when we throw an exception (error=true) causes the connection (or socket ? ) to have some residual state from previous operation, so the next select fails.
Last example throws an error (error=true) but also evicts the connection (evict=true) thus we obtain fresh connection for select and it succeedes.

Please bear in mind that we use a HikariCP with maxConnection = 1, to always reuse a connection.

Expected behaviour
If pgCopy fails, it should clean all connection/socket states on close() so that connection can be reused.

Logs
I can extract any logs that are needed, but I strongly recommend to just quickly run reproductible example (or take alook at the code). Is the error handling done wrong?

Best regards

@davecramer
Copy link
Member

So looking at your test by not reading the data from copy you are leaving data in the connection to be read using copy.
Subsequent attempts to read a resultSet will fail since the copy data is not expected.
It would appear that the test may not be representative of your real error situation.
BTW, the test code uses 42.6.0, not 42.7.2

Dave

@PiotrDuz
Copy link
Author

PiotrDuz commented Mar 13, 2024

When pgCopy faily, I am closing the PgInputStream and closing the connection.
Shouldn't PGCopyInputStream when calling close() try to release resources on db side?

Sorry for version mismatch, this problem also appears on 42.7.2 but Iw ill change here the version as in repo.

The logs are actually showing that "CancelRequest" is being sent, but still next "select" gets data from previous reuest.

startCopy FE=> Query(CopyStart) 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl processCopyResults <=BE CopyOutResponse 2024-03-13 23:45:07 FINEST org.postgresql.core.QueryExecutorBase sendQueryCancel FE=> CancelRequest(pid=72,ckey=-1,863,376,814) 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl execute simple execute, handler=org.postgresql.jdbc.PgStatement$StatementResultHandler@2127e66e, maxRows=0, fetchSize=0, flags=17 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl sendParse FE=> Parse(stmt=null,query="SELECT * from example where id=1",oids={}) 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl sendBind FE=> Bind(stmt=null,portal=null) 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl sendDescribePortal FE=> Describe(portal=null) 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl sendExecute FE=> Execute(portal=null,limit=0) 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl sendSync FE=> Sync 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl processResults <=BE CopyData 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl processResults <=BE CopyData 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl processResults <=BE CopyData 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl processResults <=BE CopyData 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl processResults <=BE CopyData 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl processResults <=BE CopyData 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl processResults <=BE CopyData 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl processResults <=BE CopyData 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl processResults <=BE CopyData 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl processResults <=BE CopyData 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl processResults <=BE CopyDone 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl receiveCommandStatus <=BE CommandStatus(COPY 10) 2024-03-13 23:45:07 FINEST org.postgresql.core.v3.QueryExecutorImpl receiveRFQ <=BE ReadyForQuery(I)

Before executing "SELECT * from example where id=1". we do have sendQueryCancel. Seems like COPY should be canceled, but after executing SELECT we get CopyData from backend

@davecramer
Copy link
Member

Yes, this is what I understand to be happening as well.
The simplest is for you to call evict instead of close.

But I'm more interested in what is happening when copy fails as it appears it hasn't really failed.

Dave

@PiotrDuz
Copy link
Author

PiotrDuz commented Mar 14, 2024

Yes, currently the eviction is the only known solution for me.
But it would be better if PGCopyInputStream could just restore the connection state properly on close().

I might not understand you correctly, is it the intended behaviour?
Should I provide more data?
Regards

@davecramer
Copy link
Member

Well it's not the "intended behaviour" but it is the behaviour.
Cancel connection is not sent out of band so the backend won't read it until it is finished sending the copy data. So when we get the connection back it is still sending the copy data.

I'm more curious what happens when copy fails. Do you have the stacktrace for that ?

@davecramer
Copy link
Member

@PiotrDuz Do you have any more information to share ?

@PiotrDuz
Copy link
Author

@davecramer sorry for the delay.
So the exception is being thrown by me in the example to break open inputStream.
When this input streams gets close() by Try block, the cancel request is thrown. It is however not really working as the next request still has data from this one cancelled.

Have you tried maybe to run my reproduction example? I think it can easily help you get more picture

@davecramer
Copy link
Member

@PiotrDuz I understand that, I want to know how the exception is being thrown in your production environment.
I can run your repro, and that behaviour is expected, and there is nothing we can do about it.

@PiotrDuz
Copy link
Author

Ah right.
So basically we have implemented a callback that handles the data from db inside try() block that guard PgCopyInputStream. In this callback we do consumption of a stream along with some business logic. This logic can throw validation exceptions. So nothing technical breaks there, rather business logic aborts operation.

@davecramer
Copy link
Member

Well I think you need to fix your app logic. This behaviour is not something we can fix at the driver level.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants