Обсуждение: Re: [JDBC] prepareThreshold=1 and statement.executeBatch() ??

On Sun, 13 Nov 2005, Joost Kraaijeveld wrote:

> I have a connection that is created with "prepareThreshold=1" in the
> connection string. I use a prepared statement that I fill with
> addbatch() and that I execute with executeBatch() (for full source: see
> "application.java" attachment).
>
> LOG:  statement: PREPARE S_2 AS update prototype.customers set title=
> $1 , defaultcurrency=$2, defaulttermsofdelivery=$3 ,
> defaulttermsofpayment=$4 where customernumber=$5
> LOG:  statement: <BIND>
> LOG:  statement: EXECUTE <unnamed>  [PREPARE:  update
> prototype.customers set title=$1 , defaultcurrency=$2, defaultter
> msofdelivery=$3, defaulttermsofpayment=$4 where customernumber=$5]
> LOG:  duration: 773.841 ms
> LOG:  statement: <BIND>
> LOG:  statement: EXECUTE <unnamed>  [PREPARE:  update
> prototype.customers set title=$1 , defaultcurrency=$2, defaultter
> msofdelivery=$3, defaulttermsofpayment=$4 where customernumber=$5]
> LOG:  duration: 377.981 ms
>
> Does this output mean that the prepared statement with the name "S_2" is
> not used in the following 2 EXECUTE statements and that therefor each
> execute statement is planned again?
>

No, this actually looks like a bug in the server side logging.  The JDBC
driver issues:

FE=> Parse(stmt=S_1,query="INSERT INTO tt VALUES ($1)",oids={23})
FE=> Bind(stmt=S_1,portal=null,$1=<1>)
FE=> Describe(portal=null)
FE=> Execute(portal=null,limit=1)
FE=> Bind(stmt=S_1,portal=null,$1=<2>)
FE=> Describe(portal=null)
FE=> Execute(portal=null,limit=1)
FE=> Sync

I assume the server side logging code is getting confused because it uses
a named statement, but the unnamed portal.

Kris Jurka

Oliver Jowett <oliver@opencloud.com> writes:
> The driver does not actually issue PREPARE or EXECUTE statements; the
> server is pretending that the protocol-level Prepare/Bind/Execute
> messages are actually something issuing PREPARE/EXECUTE at the SQL level

I had not realized that the logging code recently added to Parse/Bind/Execute
deliberately obscures the difference between a Parse message and an SQL
PREPARE (etc).  This is a terrible decision IMHO and needs to be fixed
forthwith.

            regards, tom lane

> On Sun, 13 Nov 2005, Joost Kraaijeveld wrote:
>
>> I have a connection that is created with "prepareThreshold=1" in the
>> connection string. I use a prepared statement that I fill with
>> addbatch() and that I execute with executeBatch() (for full source: see
>> "application.java" attachment).
>>
>> LOG:  statement: PREPARE S_2 AS update prototype.customers set title=
>> $1 , defaultcurrency=$2, defaulttermsofdelivery=$3 ,
>> defaulttermsofpayment=$4 where customernumber=$5
>> LOG:  statement: <BIND>
>> LOG:  statement: EXECUTE <unnamed>  [PREPARE:  update
>> prototype.customers set title=$1 , defaultcurrency=$2, defaultter
>> msofdelivery=$3, defaulttermsofpayment=$4 where customernumber=$5]
>> LOG:  duration: 773.841 ms
>> LOG:  statement: <BIND>
>> LOG:  statement: EXECUTE <unnamed>  [PREPARE:  update
>> prototype.customers set title=$1 , defaultcurrency=$2, defaultter
>> msofdelivery=$3, defaulttermsofpayment=$4 where customernumber=$5]
>> LOG:  duration: 377.981 ms
>>
>> Does this output mean that the prepared statement with the name "S_2" is
>> not used in the following 2 EXECUTE statements and that therefor each
>> execute statement is planned again?

The driver does not actually issue PREPARE or EXECUTE statements; the
server is pretending that the protocol-level Prepare/Bind/Execute
messages are actually something issuing PREPARE/EXECUTE at the SQL level
(but in reality, nothing is issuing precisely the queries that are being
logged -- the query that is submitted is just your plain "update ..."
query).

The PREPARE S_2 AS .. logs that a Prepare message was processed (for the
query "update ..."). This does parsing/planning work and creates a named
prepared statement called S_2 on the server.

The <BIND> means that some previously prepared statement (you can't tell
which statement from what is logged! -- but it's S_2 in this case) is
being bound to parameter values via a Bind message, creating an unnamed
portal.

The EXECUTE <unnamed> means the unnamed portal is being executed via an
Execute message. It also logs the underlying statement at that point,
but not the statement name (!).

So if I read the logs right, the single prepared statement S_2 *is*
being reused in the case above.

Yes, it's a horribly confusing way for the server to log things. I
raised it on -hackers earlier in the 8.1 cycle, but I've not had time to
work on it myself.

-O

Tom Lane wrote:
> Oliver Jowett <oliver@opencloud.com> writes:
> > The driver does not actually issue PREPARE or EXECUTE statements; the
> > server is pretending that the protocol-level Prepare/Bind/Execute
> > messages are actually something issuing PREPARE/EXECUTE at the SQL level
>
> I had not realized that the logging code recently added to Parse/Bind/Execute
> deliberately obscures the difference between a Parse message and an SQL
> PREPARE (etc).  This is a terrible decision IMHO and needs to be fixed
> forthwith.

The output does look slightly different and was approved by the folks
using this feature.  I don't understand the panic about it.

If people using the feature want to submit a patch to modify it, that
seems fine.

--
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073