Thread: Prepared statement leak

We seem to have identified a prepared statement leak in the JDBC driver.  The
actual application runs through Hibernate, so we have attempted to isolate
the problem here.  In the field, the problem causes the PostgreSQL server to
run out of memory in linear time.

We have tested with versions

postgresql-8.0-315.jdbc3.jar
postgresql-8.1-405.jdbc3.jar
postgresql-8.2dev-501.jdbc3.jar

with no difference.

The two prerequisites for this problem to appear are:

1. PreparedStatement objects are rebound with different types, which causes
the JDBC driver to replan the statement.

2. Batches are used.

Attached is a test program that exhibits this.  Create a database test with a
table

create table test (a int, b text);

and run the program.

I was initially at a loss about how to debug this problem so I wrote a patch
for the backend to trace the prepared statements table, which turns out to
clearly show the leak.  The attached patch is for PostgreSQL 8.0 and writes
the interesting output if log_min_messages is debug1.  (There is some extra
memory debugging code in there that I would not advise you to use.)

Running the test program you see this in the server log near the end:

DEBUG:  prepared statement hash table size = 100

It should be near 0, of course.

In the JDBC driver log output you see blocks like this:

batch execute 3 queries,
handler=org.postgresql.jdbc2.AbstractJdbc2Statement$BatchResultHandler@750159,
maxRows=0, fetchSiz
 FE=> Parse(stmt=S_1,query="INSERT INTO test VALUES ($1, $2)",oids={23,1042})
 FE=> Bind(stmt=S_1,portal=null,$1=<101>,$2=<test>)
 FE=> Describe(portal=null)
 FE=> Execute(portal=null,limit=1)
 FE=> Parse(stmt=S_2,query="INSERT INTO test VALUES ($1, $2)",oids={23,1043})
 FE=> Bind(stmt=S_2,portal=null,$1=<201>,$2=<test>)
 FE=> Describe(portal=null)
 FE=> Execute(portal=null,limit=1)
 FE=> Parse(stmt=S_3,query="INSERT INTO test VALUES ($1, $2)",oids={23,1042})
 FE=> Bind(stmt=S_3,portal=null,$1=<301>,$2=<test>)
 FE=> Describe(portal=null)
 FE=> Execute(portal=null,limit=1)
 FE=> Sync
 <=BE ParseComplete [S_3]
 <=BE BindComplete [null]
 <=BE NoData
 <=BE CommandStatus(INSERT 20239 1)
 <=BE ParseComplete [S_3]
 <=BE BindComplete [null]
 <=BE NoData
 <=BE CommandStatus(INSERT 20240 1)
 <=BE ParseComplete [S_3]
 <=BE BindComplete [null]
 <=BE NoData
 <=BE CommandStatus(INSERT 20241 1)
 <=BE ReadyForQuery(I)

Notice that it seems to forget out S_1 and S_2 along the way.

--
Peter Eisentraut
http://developer.postgresql.org/~petere/

Peter Eisentraut wrote:
> We seem to have identified a prepared statement leak in the JDBC driver.  The
> actual application runs through Hibernate, so we have attempted to isolate
> the problem here.  In the field, the problem causes the PostgreSQL server to
> run out of memory in linear time.

If you force a full GC on the Java side (i.e. call System.gc()), does
the driver clean up those leaked statements on the next query? In
theory, if the driver leaks references to a server-side prepared
statement it should reclaim the server statements when weak references
next get collected, which may take some time if the Java side is not
generating much garbage (weak references only get collected on a full
GC). Obviously we don't want to leak them in the first place, but I put
that mechanism in place in case we did.

-O

On Tue, 4 Apr 2006, Peter Eisentraut wrote:

> We seem to have identified a prepared statement leak in the JDBC driver.  The
> actual application runs through Hibernate, so we have attempted to isolate
> the problem here.  In the field, the problem causes the PostgreSQL server to
> run out of memory in linear time.
>
> The two prerequisites for this problem to appear are:
>
> 1. PreparedStatement objects are rebound with different types, which causes
> the JDBC driver to replan the statement.
>
> 2. Batches are used.
>

To cleanup prepared statements the driver records a reference to a query
object in response to the ParseComplete message.  The problem in this case
was that since the driver sends multiple Parse messages before a Sync,
when the driver receives the first ParseComplete message the query object
now contains a reference to the latest parsed statement, not the first.
So it was only cleaning up the last parsed statement not all of them.

I believe the attached patch fixes this, but I'd like Oliver to take a
look at it.  I've made included the original statement name in the list of
things available to the ParseComplete receiver so it can record the
correct original statement to be destroyed.

An ideal driver would keep only two prepared plans around, one for each
set of parameter types, but that's more complicated and for a rather
unusual situation.

Kris Jurka

Am Mittwoch, 5. April 2006 00:35 schrieb Kris Jurka:
> I believe the attached patch fixes this, but I'd like Oliver to take a
> look at it.  I've made included the original statement name in the list of
> things available to the ParseComplete receiver so it can record the
> correct original statement to be destroyed.

Your patch fixes my test case.

--
Peter Eisentraut
http://developer.postgresql.org/~petere/

On Tue, 4 Apr 2006, Kris Jurka wrote:

> On Tue, 4 Apr 2006, Peter Eisentraut wrote:
>
>> We seem to have identified a prepared statement leak in the JDBC driver.
>
> I believe the attached patch fixes this, but I'd like Oliver to take a look
> at it.  I've made included the original statement name in the list of things
> available to the ParseComplete receiver so it can record the correct original
> statement to be destroyed.
>

I've applied this patch to 8.0, 8.1, and head cvs branches and will try to
put out a new release this week.

Kris Jurka