Thread: BUG #11335: an invalid prepare statement causes crash at log_statement = 'mod' or 'ddl'.

The following bug has been logged on the website:

Bug reference:      11335
Logged by:          invalid prepare statement causes crash at log_statement = 'mod' or 'ddl'.
Email address:      harukat@sraoss.co.jp
PostgreSQL version: 9.3.5
Operating system:   CentOS 6.2 (64bit / gcc 4.4.7)
Description:


setting:
  log_statement = 'mod' # or 'ddl'

reproduction client code:
 <?php
 require_once 'MDB2.php';
 $con1 =& MDB2::connect("pgsql://postgres@localhost/db1");
 if (PEAR::isError($con1)) { die($con1->getMessage()); }
 $sth = $con1->prepare("");
 if (PEAR::isError($sth)) { die($sth->getMessage()); }
 $sth->execute();
 ?>

log messages:
 2014-09-02 19:41:57 JST 9453 LOG:  server process (PID 10372) was
 terminated by signal11: Segmentation fault
 2014-09-02 19:41:57 JST 9453 DETAIL:  Failed process was running:
 EXECUTE mdb2_statement_pgsql_9cc7dc53dfc30b3c2b937c650346f586

This occur in 9.3.5 and 9.1.14. (It probably occur at any versions.)
I tested that the following fix prevent this crash.

*** ./src/backend/tcop/utility.c    2014-09-02 19:32:44.735266203 +0900
--- ./src/backend/tcop/utility.c.ORG    2014-09-02 18:17:47.631854101 +0900
***************
*** 2307,2314 ****
  GetCommandLogLevel(Node *parsetree)
  {
      LogStmtLevel lev;
-     if (! parsetree)
-         return LOGSTMT_ALL;

      switch (nodeTag(parsetree))
      {
--- 2307,2312 ----


Though we should throw ERROR for empty prepared statement,
I hope for a symptomatic treatment such as the above.
Because an application package use such wrong query.


----------------------------------------------------------
Haruka Takatsuka
harukat@sraoss.co.jp SRA OSS, Inc. http://www.sraoss.co.jp

On Tue, Sep 2, 2014 at 8:16 PM,  <harukat@sraoss.co.jp> wrote:
> The following bug has been logged on the website:
>
> Bug reference:      11335
> Logged by:          invalid prepare statement causes crash at log_statement = 'mod' or 'ddl'.
> Email address:      harukat@sraoss.co.jp
> PostgreSQL version: 9.3.5
> Operating system:   CentOS 6.2 (64bit / gcc 4.4.7)
> Description:
>
>
> setting:
>   log_statement = 'mod' # or 'ddl'
>
> reproduction client code:
>  <?php
>  require_once 'MDB2.php';
>  $con1 =& MDB2::connect("pgsql://postgres@localhost/db1");
>  if (PEAR::isError($con1)) { die($con1->getMessage()); }
>  $sth = $con1->prepare("");
>  if (PEAR::isError($sth)) { die($sth->getMessage()); }
>  $sth->execute();
>  ?>
>
> log messages:
>  2014-09-02 19:41:57 JST 9453 LOG:  server process (PID 10372) was
>  terminated by signal11: Segmentation fault
>  2014-09-02 19:41:57 JST 9453 DETAIL:  Failed process was running:
>  EXECUTE mdb2_statement_pgsql_9cc7dc53dfc30b3c2b937c650346f586
>
> This occur in 9.3.5 and 9.1.14. (It probably occur at any versions.)
> I tested that the following fix prevent this crash.

Thanks for reporting the bug! This segmentation fault could reproduce
even on my machine. Barring any objection, I will apply the change that
you suggested.

Regards,

--
Fujii Masao

On Thu, Sep 4, 2014 at 3:55 AM, Fujii Masao <masao.fujii@gmail.com> wrote:
> On Tue, Sep 2, 2014 at 8:16 PM,  <harukat@sraoss.co.jp> wrote:
>> The following bug has been logged on the website:
>>
>> Bug reference:      11335
>> Logged by:          invalid prepare statement causes crash at log_statement = 'mod' or 'ddl'.
>> Email address:      harukat@sraoss.co.jp
>> PostgreSQL version: 9.3.5
>> Operating system:   CentOS 6.2 (64bit / gcc 4.4.7)
>> Description:
>>
>>
>> setting:
>>   log_statement = 'mod' # or 'ddl'
>>
>> reproduction client code:
>>  <?php
>>  require_once 'MDB2.php';
>>  $con1 =& MDB2::connect("pgsql://postgres@localhost/db1");
>>  if (PEAR::isError($con1)) { die($con1->getMessage()); }
>>  $sth = $con1->prepare("");
>>  if (PEAR::isError($sth)) { die($sth->getMessage()); }
>>  $sth->execute();
>>  ?>
>>
>> log messages:
>>  2014-09-02 19:41:57 JST 9453 LOG:  server process (PID 10372) was
>>  terminated by signal11: Segmentation fault
>>  2014-09-02 19:41:57 JST 9453 DETAIL:  Failed process was running:
>>  EXECUTE mdb2_statement_pgsql_9cc7dc53dfc30b3c2b937c650346f586
>>
>> This occur in 9.3.5 and 9.1.14. (It probably occur at any versions.)
>> I tested that the following fix prevent this crash.
>
> Thanks for reporting the bug! This segmentation fault could reproduce
> even on my machine. Barring any objection, I will apply the change that
> you suggested.

Done.

Regards,

--
Fujii Masao

Fujii Masao <masao.fujii@gmail.com> writes:
> On Thu, Sep 4, 2014 at 3:55 AM, Fujii Masao <masao.fujii@gmail.com> wrote:
>> Thanks for reporting the bug! This segmentation fault could reproduce
>> even on my machine. Barring any objection, I will apply the change that
>> you suggested.

> Done.

I don't think this fix is either appropriate or adequate.  Stylistically,
it's bogus that this function should be prepared for a null argument when
similar command-tag-related functions right next to it are not.  Moreover,
what is the reasoning why the correct answer for a null argument is
LOGSTMT_ALL and not something else?  It'd be at least as legit to make
it LOGSTMT_NONE, for instance.

As far as adequacy goes, the actual bug seems to be that this bit of code
is not expecting a plansource's raw_parse_tree to ever be NULL:

                /* Look through an EXECUTE to the referenced stmt */
                ps = FetchPreparedStatement(stmt->name, false);
                if (ps)
                    lev = GetCommandLogLevel(ps->plansource->raw_parse_tree);
                else
                    lev = LOGSTMT_ALL;

and it is not terribly hard to find other places making the same
assumption, which is probably reasonable because the comments around
the plansource files don't suggest it's legal either.  So I don't think
this has exhausted the number of ways to crash the backend after creating
such a prepared statement.

I think we should revert the patch as applied and instead think about
whether it's really legit to have a null raw_parse_tree in a cached plan.
If it is, the plansource comments need adjustment and so do several other
places in the code.  I'd also say that the right place to adjust
GetCommandLogLevel is in the bit I quoted above, where we know that
what we're talking about is EXECUTE on an empty prepared query, and
so there's a more principled basis for determining what its logging
level ought to be.

It might be that we'd be better off inventing some kind of EmptyStmt
parse tree for this case.  Or maybe we should reconsider whether
exec_parse_message should allow the case at all.  It's not unreasonable
that Parse should require exactly one SQL statement, not just "at most
one".

            regards, tom lane

On 2014-09-06 16:25:28 -0400, Tom Lane wrote:
> Fujii Masao <masao.fujii@gmail.com> writes:
> > On Thu, Sep 4, 2014 at 3:55 AM, Fujii Masao <masao.fujii@gmail.com> wrote:
> >> Thanks for reporting the bug! This segmentation fault could reproduce
> >> even on my machine. Barring any objection, I will apply the change that
> >> you suggested.
>
> > Done.
>
> I don't think this fix is either appropriate or adequate.

Agreed (and commented offlist. Which probably was a mistake).

> Or maybe we should reconsider whether
> exec_parse_message should allow the case at all.  It's not unreasonable
> that Parse should require exactly one SQL statement, not just "at most
> one".

I think this is the best bet. There really doesn't seem much
justification for the current "at most one" definition. At least not one
that I could find or think of. The likelihood of leaving some places
unfixed or new breakages creeping in seems non-nil; it's not what one
would immediately expect.

Greetings,

Andres Freund

--
 Andres Freund                       http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Training & Services

On Sat, Sep 6, 2014 at 1:34 PM, Andres Freund <andres@2ndquadrant.com> wrote:
> On 2014-09-06 16:25:28 -0400, Tom Lane wrote:
>> Fujii Masao <masao.fujii@gmail.com> writes:
>> > On Thu, Sep 4, 2014 at 3:55 AM, Fujii Masao <masao.fujii@gmail.com> wrote:
>> >> Thanks for reporting the bug! This segmentation fault could reproduce
>> >> even on my machine. Barring any objection, I will apply the change that
>> >> you suggested.
>>
>> > Done.
>>
>> I don't think this fix is either appropriate or adequate.
>
> Agreed (and commented offlist. Which probably was a mistake).
This has not been reverted yet. Wouldn't it be better to do that asap?
This would improve chances of seeing any potential issues in this code
path if it gets broken once again.

>> Or maybe we should reconsider whether
>> exec_parse_message should allow the case at all.  It's not unreasonable
>> that Parse should require exactly one SQL statement, not just "at most
>> one".
>
> I think this is the best bet. There really doesn't seem much
> justification for the current "at most one" definition. At least not one
> that I could find or think of. The likelihood of leaving some places
> unfixed or new breakages creeping in seems non-nil; it's not what one
> would immediately expect.
Looking at exec_parse_message, empty input string is allowed for a
cached plan (16503e6f). This solution would break client
applications/drivers using the extending query protocol and relying on
this behavior. This EmptyStmt approach sounds like a good option.
--
Michael

Michael Paquier <michael.paquier@gmail.com> writes:
> On Sat, Sep 6, 2014 at 1:34 PM, Andres Freund <andres@2ndquadrant.com> wrote:
>> On 2014-09-06 16:25:28 -0400, Tom Lane wrote:
>>> I don't think this fix is either appropriate or adequate.

>> Agreed (and commented offlist. Which probably was a mistake).

> This has not been reverted yet. Wouldn't it be better to do that asap?

Probably not until someone codes a better fix.  I have it on my plate
to look into a better fix, but I've been horribly busy lately.

> Looking at exec_parse_message, empty input string is allowed for a
> cached plan (16503e6f). This solution would break client
> applications/drivers using the extending query protocol and relying on
> this behavior. This EmptyStmt approach sounds like a good option.

Yeah, on second thought I have doubts about the throw-error approach too.
We've allowed this historically for a very long time, so I'm afraid we'd
get a lot of pushback if we change the external behavior now.  The
realistic alternatives are either to fix the code to support having
plansource->raw_parse_tree be NULL, or to invent a dummy node type to
put there.  Not sure which is better.

            regards, tom lane

On 2014-09-17 14:56:42 -0700, Tom Lane wrote:
> Michael Paquier <michael.paquier@gmail.com> writes:
> > On Sat, Sep 6, 2014 at 1:34 PM, Andres Freund <andres@2ndquadrant.com> wrote:
> > Looking at exec_parse_message, empty input string is allowed for a
> > cached plan (16503e6f). This solution would break client
> > applications/drivers using the extending query protocol and relying on
> > this behavior. This EmptyStmt approach sounds like a good option.
>
> Yeah, on second thought I have doubts about the throw-error approach too.
> We've allowed this historically for a very long time, so I'm afraid we'd
> get a lot of pushback if we change the external behavior now.

I have a hard time believing this. Are we really believing that there's
a significant number of clients preparing whitespace?

We imo should at least change it in master. Unless I miss something
there's really no reason for allowing it.

Greetings,

Andres Freund

--
 Andres Freund                       http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Training & Services

Andres Freund <andres@2ndquadrant.com> writes:
> On 2014-09-17 14:56:42 -0700, Tom Lane wrote:
>> Yeah, on second thought I have doubts about the throw-error approach too.
>> We've allowed this historically for a very long time, so I'm afraid we'd
>> get a lot of pushback if we change the external behavior now.

> I have a hard time believing this. Are we really believing that there's
> a significant number of clients preparing whitespace?

I don't know about "significant number", but the case is specifically
called out as legal in the FE/BE protocol spec, for example here:

   Therefore, an Execute phase is always terminated by the appearance of
   exactly one of these messages: CommandComplete, EmptyQueryResponse
   (if the portal was created from an empty query string), ErrorResponse,
   or PortalSuspended.

If we change it, that's a protocol break, and I don't think that being a
tad cleaner is sufficient argument for that.

            regards, tom lane

>> I have a hard time believing this. Are we really believing that there's
>> a significant number of clients preparing whitespace?
>
> I don't know about "significant number", but the case is specifically
> called out as legal in the FE/BE protocol spec, for example here:
>
>    Therefore, an Execute phase is always terminated by the appearance of
>    exactly one of these messages: CommandComplete, EmptyQueryResponse
>    (if the portal was created from an empty query string), ErrorResponse,
>    or PortalSuspended.
>
> If we change it, that's a protocol break, and I don't think that being a
> tad cleaner is sufficient argument for that.

Agreed. Thinking about that the simple protocol allows to use an empty
query string, there's no reason to not allow it for the extended protocol.

Best regards,
--
Tatsuo Ishii
SRA OSS, Inc. Japan
English: http://www.sraoss.co.jp/index_en.php
Japanese:http://www.sraoss.co.jp

On Wed, Sep 17, 2014 at 05:10:52PM -0700, Tom Lane wrote:
> Andres Freund <andres@2ndquadrant.com> writes:
> > On 2014-09-17 14:56:42 -0700, Tom Lane wrote:
> >> Yeah, on second thought I have doubts about the throw-error approach too.
> >> We've allowed this historically for a very long time, so I'm afraid we'd
> >> get a lot of pushback if we change the external behavior now.
>
> > I have a hard time believing this. Are we really believing that there's
> > a significant number of clients preparing whitespace?
>
> I don't know about "significant number", but the case is specifically
> called out as legal in the FE/BE protocol spec, for example here:
>
>    Therefore, an Execute phase is always terminated by the appearance of
>    exactly one of these messages: CommandComplete, EmptyQueryResponse
>    (if the portal was created from an empty query string), ErrorResponse,
>    or PortalSuspended.
>
> If we change it, that's a protocol break, and I don't think that being a
> tad cleaner is sufficient argument for that.

Where are we on this?

--
  Bruce Momjian  <bruce@momjian.us>        http://momjian.us
  EnterpriseDB                             http://enterprisedb.com

  + Everyone has their own god. +

I wrote:
> Michael Paquier <michael.paquier@gmail.com> writes:
>> On Sat, Sep 6, 2014 at 1:34 PM, Andres Freund <andres@2ndquadrant.com> wrote:
>>> On 2014-09-06 16:25:28 -0400, Tom Lane wrote:
>>>> I don't think this fix is either appropriate or adequate.

>>> Agreed (and commented offlist. Which probably was a mistake).

>> This has not been reverted yet. Wouldn't it be better to do that asap?

> Probably not until someone codes a better fix.  I have it on my plate
> to look into a better fix, but I've been horribly busy lately.

I've applied a fix that takes the approach of explicitly testing for
null plancache->raw_parse_tree whereever necessary.  There were at least
two places where there was no such test before; I think they are probably
unreachable with an empty query (because no replanning could ever be
needed) but it seems best to be consistent.

            regards, tom lane