Thread: binary patch problems
I have applied to the current code and the tests fail with ResultSet already closed. I can't replicate this in eclipse, only in the command line ant test. My guess is that somehow result sets are being shared across tests. Anyone shed some light on this ? The patch I applied is at http://wiki.postgresql.org/wiki/JDBC-BinaryTransfer version 13 Dave Cramer dave.cramer(at)credativ(dot)ca http://www.credativ.ca
On 09/16/2011 01:10 AM, Dave Cramer wrote: > I have applied to the current code and the tests fail with ResultSet > already closed. I can't replicate this in eclipse, only in the command > line ant test. My guess is that somehow result sets are being shared > across tests. Anyone shed some light on this ? The patch I applied is > at http://wiki.postgresql.org/wiki/JDBC-BinaryTransfer version 13 > Dave Cramer I've been lately trying to figure out the same problem. In separate emails I just sent the refreshed set of patches broken into separate patches out for easier review. The trace shows that for some reason the C_5 portal is closed while still processing the results. (3) FE=> Execute(portal=C_5,limit=1) (3) FE=> Sync (3) <=BE DataRow(len=305) (3) <=BE PortalSuspended (3) <=BE ReadyForQuery(T) (3) FE=> Execute(portal=C_5,limit=1) (3) FE=> Sync (3) <=BE DataRow(len=305) (3) <=BE PortalSuspended (3) <=BE ReadyForQuery(T) (3) FE=> CloseStatement(S_2) (3) FE=> ClosePortal(C_5) (3) FE=> Execute(portal=C_5,limit=1) (3) FE=> Sync (3) <=BE CloseComplete (3) <=BE CloseComplete (3) <=BE ErrorMessage(ERROR: portal "C_5" does not exist Location: File: postgres.c, Routine: exec_execute_message, Line: 1844 Server SQLState: 34000) org.postgresql.util.PSQLException: ERROR: portal "C_5" does not exist Location: File: postgres.c, Routine: exec_execute_message, Line: 1844 Server SQLState: 34000 at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2158) at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1887) at org.postgresql.core.v3.QueryExecutorImpl.fetch(QueryExecutorImpl.java:2090) at org.postgresql.jdbc2.AbstractJdbc2ResultSet.next(AbstractJdbc2ResultSet.java:1870) at org.postgresql.test.jdbc2.DatabaseEncodingTest.testEncoding(DatabaseEncodingTest.java:149) The C_5 portal is closed because it is in the openPortalCleanupQueue containing PhantomReferences. The trace shows that S_2is also closed at the same time, which is correct because that statement is no longer in use. If I debugged it correctly it looks like the query statement is closed by finalizer during the test which in turn closesthe relevant portals. If I add stmt.close() to the end of the test there are no failures as it keeps the GC from killing of the statement duringthe test. But why I only seem to get it when running with binary transfer patches I do not know. So there must be something in thepatches that I cannot spot. -Mikko
Interestingly enough I only get that particular problem when I run it directly after an ant clean, if I run subsequent tests then I get result set is already closed errors. I applied v13 patch successfully. Is there a necessity to use the patches you have just sent ? Dave Cramer dave.cramer(at)credativ(dot)ca http://www.credativ.ca On Fri, Sep 16, 2011 at 8:20 AM, Mikko Tiihonen <mikko.tiihonen@nitorcreations.com> wrote: > On 09/16/2011 01:10 AM, Dave Cramer wrote: >> >> I have applied to the current code and the tests fail with ResultSet >> already closed. I can't replicate this in eclipse, only in the command >> line ant test. My guess is that somehow result sets are being shared >> across tests. Anyone shed some light on this ? The patch I applied is >> at http://wiki.postgresql.org/wiki/JDBC-BinaryTransfer version 13 >> Dave Cramer > > I've been lately trying to figure out the same problem. > In separate emails I just sent the refreshed set of patches broken into > separate patches out for easier review. > > The trace shows that for some reason the C_5 portal is closed while still > processing the results. > > (3) FE=> Execute(portal=C_5,limit=1) > (3) FE=> Sync > (3) <=BE DataRow(len=305) > (3) <=BE PortalSuspended > (3) <=BE ReadyForQuery(T) > (3) FE=> Execute(portal=C_5,limit=1) > (3) FE=> Sync > (3) <=BE DataRow(len=305) > (3) <=BE PortalSuspended > (3) <=BE ReadyForQuery(T) > (3) FE=> CloseStatement(S_2) > (3) FE=> ClosePortal(C_5) > (3) FE=> Execute(portal=C_5,limit=1) > (3) FE=> Sync > (3) <=BE CloseComplete > (3) <=BE CloseComplete > (3) <=BE ErrorMessage(ERROR: portal "C_5" does not exist > Location: File: postgres.c, Routine: exec_execute_message, Line: 1844 > Server SQLState: 34000) > org.postgresql.util.PSQLException: ERROR: portal "C_5" does not exist > Location: File: postgres.c, Routine: exec_execute_message, Line: 1844 > Server SQLState: 34000 > at > org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2158) > at > org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1887) > at > org.postgresql.core.v3.QueryExecutorImpl.fetch(QueryExecutorImpl.java:2090) > at > org.postgresql.jdbc2.AbstractJdbc2ResultSet.next(AbstractJdbc2ResultSet.java:1870) > at > org.postgresql.test.jdbc2.DatabaseEncodingTest.testEncoding(DatabaseEncodingTest.java:149) > > The C_5 portal is closed because it is in the openPortalCleanupQueue > containing PhantomReferences. The trace shows that S_2 is also closed at the > same > time, which is correct because that statement is no longer in use. > > If I debugged it correctly it looks like the query statement is closed by > finalizer during the test which in turn closes the relevant portals. > If I add stmt.close() to the end of the test there are no failures as it > keeps the GC from killing of the statement during the test. > > But why I only seem to get it when running with binary transfer patches I do > not know. So there must be something in the patches that I cannot spot. > > -Mikko > > -- > Sent via pgsql-jdbc mailing list (pgsql-jdbc@postgresql.org) > To make changes to your subscription: > http://www.postgresql.org/mailpref/pgsql-jdbc >
On 17 September 2011 01:20, Mikko Tiihonen
<mikko.tiihonen@nitorcreations.com> wrote:
> If I debugged it correctly it looks like the query statement is closed by
> finalizer during the test which in turn closes the relevant portals.
> If I add stmt.close() to the end of the test there are no failures as it
> keeps the GC from killing of the statement during the test.
>
> But why I only seem to get it when running with binary transfer patches I do
> not know. So there must be something in the patches that I cannot spot.
(I am halfway through my first coffee of the day. YMMV)
The test code holds a reference to the returned ResultSet, but doesn't
keep a reference to the Statement itself after calling executeQuery().
Normally this isn't a problem because there is a strong ref from a
ResultSet to its owning Statement, so while you are using a particular
ResultSet the creating statement remains reachable.
The problem seems to be introduced in the patch to executeQuery if
(ForceBinaryTransfers). This delegates to a new PreparedStatement
("inner PreparedStatement") and splices its resultset ("inner
resultset") back into the surrounding Statement ("outer Statement")
and returns that.
However the inner ResultSet has the wrong parent Statement for that
context (ResultSet.getStatement() will return the "inner
PreparedStatement" not the "outer Statement") - which is a separate
problem, but also causes the GC problems as well, as now there's no
strong ref from the returned ResultSet to the Statement that the
client created it via.
So in the test code we end up with:
(a) a strong ref to the inner ResultSet, directly; and
(b) a strong ref to the inner PreparedStatement, via the statement
reference of the inner ResultSet.
.. but no strong ref to the outer Statement. So the outer Statement
becomes garbage right after the call to executeQuery(), and if you are
unlucky with GC timing, it can be finalized and closed under you,
which then closes the inner ResultSet.
Adding a call to stmt.close() means that the outer Statement still has
a strong reference directly from test code up until that point, so it
doesn't get finalized early.
At a glance, executeQuery() is also broken for queries that return
multiple resultsets if ForceBinaryTransfers is enabled - you only get
the first resultset back.
Oliver
On 09/16/2011 04:40 PM, Dave Cramer wrote: > I applied v13 patch successfully. Is there a necessity to use the > patches you have just sent ? Not really. The only functional difference is with ResulSet.getBoolean of a numeric type, which in the older v13 patches differed from the text protocol handling. -Mikko
On 09/17/2011 02:14 AM, Oliver Jowett wrote:
> On 17 September 2011 01:20, Mikko Tiihonen
> <mikko.tiihonen@nitorcreations.com> wrote:
>
>> If I debugged it correctly it looks like the query statement is closed by
>> finalizer during the test which in turn closes the relevant portals.
>> If I add stmt.close() to the end of the test there are no failures as it
>> keeps the GC from killing of the statement during the test.
>>
>> But why I only seem to get it when running with binary transfer patches I do
>> not know. So there must be something in the patches that I cannot spot.
>
> (I am halfway through my first coffee of the day. YMMV)
>
> The test code holds a reference to the returned ResultSet, but doesn't
> keep a reference to the Statement itself after calling executeQuery().
> Normally this isn't a problem because there is a strong ref from a
> ResultSet to its owning Statement, so while you are using a particular
> ResultSet the creating statement remains reachable.
>
> The problem seems to be introduced in the patch to executeQuery if
> (ForceBinaryTransfers). This delegates to a new PreparedStatement
> ("inner PreparedStatement") and splices its resultset ("inner
> resultset") back into the surrounding Statement ("outer Statement")
> and returns that.
>
> However the inner ResultSet has the wrong parent Statement for that
> context (ResultSet.getStatement() will return the "inner
> PreparedStatement" not the "outer Statement") - which is a separate
> problem, but also causes the GC problems as well, as now there's no
> strong ref from the returned ResultSet to the Statement that the
> client created it via.
>
> So in the test code we end up with:
> (a) a strong ref to the inner ResultSet, directly; and
> (b) a strong ref to the inner PreparedStatement, via the statement
> reference of the inner ResultSet.
>
> .. but no strong ref to the outer Statement. So the outer Statement
> becomes garbage right after the call to executeQuery(), and if you are
> unlucky with GC timing, it can be finalized and closed under you,
> which then closes the inner ResultSet.
>
> Adding a call to stmt.close() means that the outer Statement still has
> a strong reference directly from test code up until that point, so it
> doesn't get finalized early.
>
> At a glance, executeQuery() is also broken for queries that return
> multiple resultsets if ForceBinaryTransfers is enabled - you only get
> the first resultset back.
Thank you for the thorough analysis. Now we need to decide what to do
with the ForceBinaryTransfers testing/debugging aid.
It was originally added to ensure that while running the unit tests
as much as possible of the code paths would exercise the binary transfer
code. Normally binary transfers would only be activated after few
round-trips to the backend with the same prepared statement - which
basically never happens in unit tests.
We have at least three options:
1) drop the ForceBinaryTransfers
- it has helpped debug the binary transfer to a working state
- it is no longer that useful
2) leave it as is
- just add the hack to the one failing test to make it not fail
- it is still useful to run the test suite to verify functionality
stays correct with binary transfers
3) fix it
- less worries in the future and if some end user finds the
undocumented feature they won't get bitten by it
-Mikko
Hi Mikko, My suggestion would be to fix it. Dave Cramer dave.cramer(at)credativ(dot)ca http://www.credativ.ca On Fri, Sep 16, 2011 at 7:14 PM, Oliver Jowett <oliver@opencloud.com> wrote: > On 17 September 2011 01:20, Mikko Tiihonen > <mikko.tiihonen@nitorcreations.com> wrote: > >> If I debugged it correctly it looks like the query statement is closed by >> finalizer during the test which in turn closes the relevant portals. >> If I add stmt.close() to the end of the test there are no failures as it >> keeps the GC from killing of the statement during the test. >> >> But why I only seem to get it when running with binary transfer patches I do >> not know. So there must be something in the patches that I cannot spot. > > (I am halfway through my first coffee of the day. YMMV) > > The test code holds a reference to the returned ResultSet, but doesn't > keep a reference to the Statement itself after calling executeQuery(). > Normally this isn't a problem because there is a strong ref from a > ResultSet to its owning Statement, so while you are using a particular > ResultSet the creating statement remains reachable. > > The problem seems to be introduced in the patch to executeQuery if > (ForceBinaryTransfers). This delegates to a new PreparedStatement > ("inner PreparedStatement") and splices its resultset ("inner > resultset") back into the surrounding Statement ("outer Statement") > and returns that. > > However the inner ResultSet has the wrong parent Statement for that > context (ResultSet.getStatement() will return the "inner > PreparedStatement" not the "outer Statement") - which is a separate > problem, but also causes the GC problems as well, as now there's no > strong ref from the returned ResultSet to the Statement that the > client created it via. > > So in the test code we end up with: > (a) a strong ref to the inner ResultSet, directly; and > (b) a strong ref to the inner PreparedStatement, via the statement > reference of the inner ResultSet. > > .. but no strong ref to the outer Statement. So the outer Statement > becomes garbage right after the call to executeQuery(), and if you are > unlucky with GC timing, it can be finalized and closed under you, > which then closes the inner ResultSet. > > Adding a call to stmt.close() means that the outer Statement still has > a strong reference directly from test code up until that point, so it > doesn't get finalized early. > > At a glance, executeQuery() is also broken for queries that return > multiple resultsets if ForceBinaryTransfers is enabled - you only get > the first resultset back. > > Oliver >
On 09/19/2011 01:03 PM, Dave Cramer wrote:
> Hi Mikko,
>
> My suggestion would be to fix it.
Finally had some time to look into this.
Closing the result set of the describe query fixes the test failure for me.
-Mikko
--- org/postgresql/jdbc2/AbstractJdbc2Statement.java.orig 2011-09-20 16:55:18.130947602 +0300
+++ org/postgresql/jdbc2/AbstractJdbc2Statement.java 2011-09-20 16:56:02.310694214 +0300
@@ -541,6 +541,8 @@
int flags2 = flags | QueryExecutor.QUERY_DESCRIBE_ONLY;
StatementResultHandler handler2 = new StatementResultHandler();
connection.getQueryExecutor().execute(queryToExecute, queryParameters, handler2, 0, 0, flags2);
+ ResultWrapper result2 = handler2.getResults();
+ result2.getResultSet().close();
}
StatementResultHandler handler = new StatementResultHandler();
> On Fri, Sep 16, 2011 at 7:14 PM, Oliver Jowett<oliver@opencloud.com> wrote:
>> On 17 September 2011 01:20, Mikko Tiihonen
>> <mikko.tiihonen@nitorcreations.com> wrote:
>>
>>> If I debugged it correctly it looks like the query statement is closed by
>>> finalizer during the test which in turn closes the relevant portals.
>>> If I add stmt.close() to the end of the test there are no failures as it
>>> keeps the GC from killing of the statement during the test.
>>>
>>> But why I only seem to get it when running with binary transfer patches I do
>>> not know. So there must be something in the patches that I cannot spot.
>>
>> (I am halfway through my first coffee of the day. YMMV)
>>
>> The test code holds a reference to the returned ResultSet, but doesn't
>> keep a reference to the Statement itself after calling executeQuery().
>> Normally this isn't a problem because there is a strong ref from a
>> ResultSet to its owning Statement, so while you are using a particular
>> ResultSet the creating statement remains reachable.
>>
>> The problem seems to be introduced in the patch to executeQuery if
>> (ForceBinaryTransfers). This delegates to a new PreparedStatement
>> ("inner PreparedStatement") and splices its resultset ("inner
>> resultset") back into the surrounding Statement ("outer Statement")
>> and returns that.
>>
>> However the inner ResultSet has the wrong parent Statement for that
>> context (ResultSet.getStatement() will return the "inner
>> PreparedStatement" not the "outer Statement") - which is a separate
>> problem, but also causes the GC problems as well, as now there's no
>> strong ref from the returned ResultSet to the Statement that the
>> client created it via.
>>
>> So in the test code we end up with:
>> (a) a strong ref to the inner ResultSet, directly; and
>> (b) a strong ref to the inner PreparedStatement, via the statement
>> reference of the inner ResultSet.
>>
>> .. but no strong ref to the outer Statement. So the outer Statement
>> becomes garbage right after the call to executeQuery(), and if you are
>> unlucky with GC timing, it can be finalized and closed under you,
>> which then closes the inner ResultSet.
>>
>> Adding a call to stmt.close() means that the outer Statement still has
>> a strong reference directly from test code up until that point, so it
>> doesn't get finalized early.
>>
>> At a glance, executeQuery() is also broken for queries that return
>> multiple resultsets if ForceBinaryTransfers is enabled - you only get
>> the first resultset back.
>>
>> Oliver
>>
On 21 September 2011 02:00, Mikko Tiihonen <mikko.tiihonen@nitorcreations.com> wrote: > On 09/19/2011 01:03 PM, Dave Cramer wrote: >> >> Hi Mikko, >> >> My suggestion would be to fix it. > > Finally had some time to look into this. > Closing the result set of the describe query fixes the test failure for me. That code path only runs on the "inner" statement in this case, doesn't it? Oliver
Hi Mikko, So I applied that patch now I run out of connections and I have my server configured for 100 connections. Dave Cramer dave.cramer(at)credativ(dot)ca http://www.credativ.ca On Tue, Sep 20, 2011 at 10:47 AM, Oliver Jowett <oliver@opencloud.com> wrote: > On 21 September 2011 02:00, Mikko Tiihonen > <mikko.tiihonen@nitorcreations.com> wrote: >> On 09/19/2011 01:03 PM, Dave Cramer wrote: >>> >>> Hi Mikko, >>> >>> My suggestion would be to fix it. >> >> Finally had some time to look into this. >> Closing the result set of the describe query fixes the test failure for me. > > That code path only runs on the "inner" statement in this case, doesn't it? > > Oliver >