Обсуждение: trailing comment ghost-timing

With \timing on, a trailing comment yields a timing.

# test.sql
select 1;

/*
select 2
*/

$ psql -f test.sql?column?
----------       1
(1 row)

Time: 0.651 ms
Time: 0.089 ms

I assume it is timing something about that comment (right?).

Confusing and annoying, IMHO.  Is there any chance such trailing ghost-timings can be removed?

BTW:
$ cat ~/.psqlrc
\set QUIET on
\timing on


Thanks,

Erik Rijkers

On 12/24/2013 02:05 AM, Erik Rijkers wrote:
> With \timing on, a trailing comment yields a timing.
>
> # test.sql
> select 1;
>
> /*
> select 2
> */
>
> $ psql -f test.sql
>   ?column?
> ----------
>          1
> (1 row)
>
> Time: 0.651 ms
> Time: 0.089 ms
>
> I assume it is timing something about that comment (right?).
>
> Confusing and annoying, IMHO.  Is there any chance such trailing ghost-timings can be removed?

This seems to be caused by psql sending the comment to the server to 
evaluate as a query. I personally think timing should always output 
something for every command sent to the server. To fix this problem I 
guess one would have to modify psql_scan() to check if a scanned query 
only contains comments and then not send it to the server at all.

The minimal file to reproduce it is:

/**/

-- 
Andreas Karlsson

Andreas Karlsson wrote
> On 12/24/2013 02:05 AM, Erik Rijkers wrote:
>> With \timing on, a trailing comment yields a timing.
>>
>> # test.sql
>> select 1;
>>
>> /*
>> select 2
>> */
>>
>> $ psql -f test.sql
>>   ?column?
>> ----------
>>          1
>> (1 row)
>>
>> Time: 0.651 ms
>> Time: 0.089 ms
>>
>> I assume it is timing something about that comment (right?).
>>
>> Confusing and annoying, IMHO.  Is there any chance such trailing
>> ghost-timings can be removed?
> 
> This seems to be caused by psql sending the comment to the server to 
> evaluate as a query. I personally think timing should always output 
> something for every command sent to the server. To fix this problem I 
> guess one would have to modify psql_scan() to check if a scanned query 
> only contains comments and then not send it to the server at all.
> 
> The minimal file to reproduce it is:
> 
> /**/
> 
> -- 
> Andreas Karlsson

I need to be convinced that the server should not just silently ignore
trailing comments.  I'd consider an exception if the only text sent is a
comment ( in such a case we should throw an error ) but if valid commands
are sent and there is just some comment text at the end it should be ignored
the same as if the comments were embedded in the middle of the query text.

I've encountered other clients that output phantom results in this situation
and solving it at the server seems worthwhile so client applications do not
have to care.

In the example case, I think, putting the comment before the command results
in only one timing.  This inconsistency is a symptom of this situation being
handled incorrectly.

David J.





--
View this message in context:
http://postgresql.1045698.n5.nabble.com/trailing-comment-ghost-timing-tp5784473p5784484.html
Sent from the PostgreSQL - hackers mailing list archive at Nabble.com.

On 12/24/2013 03:17 AM, David Johnston wrote:
> I need to be convinced that the server should not just silently ignore
> trailing comments.  I'd consider an exception if the only text sent is a
> comment ( in such a case we should throw an error ) but if valid commands
> are sent and there is just some comment text at the end it should be ignored
> the same as if the comments were embedded in the middle of the query text.
>
> I've encountered other clients that output phantom results in this situation
> and solving it at the server seems worthwhile so client applications do not
> have to care.
>
> In the example case, I think, putting the comment before the command results
> in only one timing.  This inconsistency is a symptom of this situation being
> handled incorrectly.

It is not sent to the server as a trailing comment. The following file 
is sent to the server like this.

File:
/**/;
/**/

Commands:
PQexec(..., "/**/;");
PQexec(..., "/**/");

If this has to be fixed it should be in the client. I think people would 
complain if we broke the API by starting to throw an exception on PQexec 
with a string containing no actual query.

-- 
Andreas Karlsson

On Tue, Dec 24, 2013 at 03:40:58AM +0100, Andreas Karlsson wrote:
> On 12/24/2013 03:17 AM, David Johnston wrote:
> It is not sent to the server as a trailing comment. The following
> file is sent to the server like this.
>
> File:
> /**/;
> /**/
>
> Commands:
> PQexec(..., "/**/;");
> PQexec(..., "/**/");
>
> If this has to be fixed it should be in the client. I think people
> would complain if we broke the API by starting to throw an exception
> on PQexec with a string containing no actual query.

(Untested). Isn't this just a case of psql not printing out a timing if
the server responds with PGRES_EMPTY_QUERY?

Have a nice day,
--
Martijn van Oosterhout   <kleptog@svana.org>   http://svana.org/kleptog/
> He who writes carelessly confesses thereby at the very outset that he does
> not attach much importance to his own thoughts.  -- Arthur Schopenhauer

On 12/24/13, 5:40 AM, Fabrízio de Royes Mello wrote:
>> (Untested). Isn't this just a case of psql not printing out a timing if
>> the server responds with PGRES_EMPTY_QUERY?
>>
> 
> Works... look to the attached patch!

That looks reasonable.

Hi,

On 2013-12-24 02:05:23 +0100, Erik Rijkers wrote:
> With \timing on, a trailing comment yields a timing.
> 
> # test.sql
> select 1;
> 
> /*
> select 2
> */
> 
> $ psql -f test.sql
>  ?column?
> ----------
>         1
> (1 row)
> 
> Time: 0.651 ms
> Time: 0.089 ms
> 
> I assume it is timing something about that comment (right?).
> 
> Confusing and annoying, IMHO.  Is there any chance such trailing ghost-timings can be removed?

Maybe I am thinking to technical here, but why would that be a good
idea? After all, the comment will have triggered sending a statement to
the server and waiting for the result. The user might want to know about
that.

Greetings,

Andres Freund

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

On Tue, December 24, 2013 15:19, Andres Freund wrote:
> Hi,
>
> On 2013-12-24 02:05:23 +0100, Erik Rijkers wrote:
>> With \timing on, a trailing comment yields a timing.
>>
>> # test.sql
>> select 1;
>>
>> /*
>> select 2
>> */
>>
>> $ psql -f test.sql
>>  ?column?
>> ----------
>>         1
>> (1 row)
>>
>> Time: 0.651 ms
>> Time: 0.089 ms
>>
>> I assume it is timing something about that comment (right?).
>>
>> Confusing and annoying, IMHO.  Is there any chance such trailing ghost-timings can be removed?
>
> Maybe I am thinking to technical here, but why would that be a good
> idea? After all, the comment will have triggered sending a statement to
> the server and waiting for the result. The user might want to know about
> that.

Technical or non-technical; it's at least pretty inconsistent:
- it only times with the last comment.
- it only times with the /**/ comment; to time your trailing -- comments you'll have to find another solution :)

Obviously it's a minor thing, and I don't care if it does not get removed, but I don't think you can argue that it
serves
any useful purpose in the current state.


Erik Rijkers

Andres Freund <andres@2ndquadrant.com> writes:
> Maybe I am thinking to technical here, but why would that be a good
> idea? After all, the comment will have triggered sending a statement to
> the server and waiting for the result. The user might want to know about
> that.

I agree; if we triggered a server operation, we should report a timing.
Pretending we did not isn't a good solution.

The real question is whether we shouldn't suppress the whole PQexec.
I believe this is very closely related to the question of what we do
with a comment preceding the next command.  Try this experiment:

regression=# set log_statement = 'all';
SET
regression=# /* block comment here */
regression-# select 2+2;?column? 
----------       4
(1 row)

regression=# -- dash comment here
regression=# select 3+3;?column? 
----------       6
(1 row)

and then look in the postmaster log:

LOG:  statement: /* block comment here */       select 2+2;
LOG:  statement: select 3+3;

This is inconsistent, IMO.  I think if we were to fix things so that
leading block comments were dropped the same way -- comments are, that
would also take care of the behavior complained of in this thread.
There's been some previous discussion of this point, I think.

A related issue is that psql suppresses -- comments after the start of
the SQL statement as well as before it.  I think that this is probably not
such a good idea anymore; it has the potential at least to screw up
psql's reporting of error locations.  I think what would likely be the
ideal behavior is to drop all leading lines containing only
whitespace/comments, but once we identify the "first line of the
statement", transmit verbatim up till the closing semicolon.

Fun corner case:
   /* block comment      here */ SELECT ...

If we try to strip this comment we're definitely going to have issues with
error cursor positions.  So probably the way it will have to work is to
make a check at each end-of-line about whether we are outside any block
comment and haven't seen any SQL token yet, and flush the query collection
buffer if so.
        regards, tom lane

> The real question is whether we shouldn't suppress the whole PQexec.
> I believe this is very closely related to the question of what we do
> with a comment preceding the next command.  Try this experiment:

> regression=# /* block comment here */
> regression-# select 2+2;

> regression=# -- dash comment here
> regression=# select 3+3;

> and then look in the postmaster log:
> 
> LOG:  statement: /* block comment here */
>         select 2+2;
> LOG:  statement: select 3+3;
> 
> This is inconsistent, IMO.  I think if we were to fix things so that
> leading block comments were dropped the same way -- comments are, that
> would also take care of the behavior complained of in this thread.
> There's been some previous discussion of this point, I think.

FWIW, I find dropping comments a rather annoying behaviour. I'd rather
include dash comments in the statements sent to the server than start
dropping block comments.
It's not uncommon to annotate statements with additional information
using comments for log analysis. Sure, most of that isn't sent via psql,
but it's imo still surpising when testing or re-executing stuff from the log.

Greetings,

Andres Freund

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

Andres Freund <andres@2ndquadrant.com> writes:
>> This is inconsistent, IMO.  I think if we were to fix things so that
>> leading block comments were dropped the same way -- comments are, that
>> would also take care of the behavior complained of in this thread.
>> There's been some previous discussion of this point, I think.

> FWIW, I find dropping comments a rather annoying behaviour. I'd rather
> include dash comments in the statements sent to the server than start
> dropping block comments.

What I was proposing was that we do include comments in what we send,
as long as those comments are embedded in the statement text, not
on lines before it.
        regards, tom lane

On 12/24/2013 08:53 AM, Martijn van Oosterhout wrote:
> (Untested). Isn't this just a case of psql not printing out a timing if
> the server responds with PGRES_EMPTY_QUERY?

Yes, it is. Sorry should have made myself more clear (way more clear 
when I read my messages from yesterday). Then I thought the server 
should print timing even if PGRES_EMPTY_QUERY is returned. Now after 
thinking on it I am not so sure.

-- 
Andreas Karlsson

On 2013-12-24 12:27:59 -0500, Tom Lane wrote:
> Andres Freund <andres@2ndquadrant.com> writes:
> >> This is inconsistent, IMO.  I think if we were to fix things so that
> >> leading block comments were dropped the same way -- comments are, that
> >> would also take care of the behavior complained of in this thread.
> >> There's been some previous discussion of this point, I think.
> 
> > FWIW, I find dropping comments a rather annoying behaviour. I'd rather
> > include dash comments in the statements sent to the server than start
> > dropping block comments.
> 
> What I was proposing was that we do include comments in what we send,
> as long as those comments are embedded in the statement text, not
> on lines before it.

The common way I've seen what I've described above done as is something
like:
/* File:path/to/some/file.whatever Function:foo::something()* Comment: Expensive, but that's ok!*/
SELECT here_comes FROM my WHERE some_sql;

If I unerstood what you propose correctly, we'd now drop that comment,
where we sent it before?

Greetings,

Andres Freund

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

Andres Freund <andres@2ndquadrant.com> writes:
> On 2013-12-24 12:27:59 -0500, Tom Lane wrote:
>> What I was proposing was that we do include comments in what we send,
>> as long as those comments are embedded in the statement text, not
>> on lines before it.

> The common way I've seen what I've described above done as is something
> like:
> /* File:path/to/some/file.whatever Function:foo::something()
>  * Comment: Expensive, but that's ok!
>  */
> SELECT here_comes FROM my WHERE some_sql;

> If I unerstood what you propose correctly, we'd now drop that comment,
> where we sent it before?

Yeah.  But I just noticed that this would cause the regression test
results to change dramatically --- right now, most "-- comment" comments
get echoed to the output, and that would stop.  So maybe it's not such
a great idea after all.
        regards, tom lane

On Sat, Dec 28, 2013 at 08:20:59PM -0500, Tom Lane wrote:
> Andres Freund <andres@2ndquadrant.com> writes:
> > On 2013-12-24 12:27:59 -0500, Tom Lane wrote:
> >> What I was proposing was that we do include comments in what we send,
> >> as long as those comments are embedded in the statement text, not
> >> on lines before it.
> 
> > The common way I've seen what I've described above done as is something
> > like:
> > /* File:path/to/some/file.whatever Function:foo::something()
> >  * Comment: Expensive, but that's ok!
> >  */
> > SELECT here_comes FROM my WHERE some_sql;
> 
> > If I unerstood what you propose correctly, we'd now drop that comment,
> > where we sent it before?
> 
> Yeah.  But I just noticed that this would cause the regression test
> results to change dramatically --- right now, most "-- comment" comments
> get echoed to the output, and that would stop.  So maybe it's not such
> a great idea after all.

Where are we on this?  It seem odd that psql sends /* */ comments to the
server, but not "--" comments.  Should this be documented or changed?

I am confused why changing the behavior would affect the regression test
output as -- and /* */ comments already appear, and it was stated that
"--" comments are already not sent to the server.

Everyone agreed that suppressing \timing output for a PGRES_EMPTY_QUERY
return result was not a good idea.

--  Bruce Momjian  <bruce@momjian.us>        http://momjian.us EnterpriseDB
http://enterprisedb.com
 + Everyone has their own god. +

On Mon, Mar 31, 2014 at 02:06:28PM -0400, Bruce Momjian wrote:
> Where are we on this?  It seem odd that psql sends /* */ comments to the
> server, but not "--" comments.  Should this be documented or changed?
>
> I am confused why changing the behavior would affect the regression test
> output as -- and /* */ comments already appear, and it was stated that
> "--" comments are already not sent to the server.
>
> Everyone agreed that suppressing \timing output for a PGRES_EMPTY_QUERY
> return result was not a good idea.

I have applied the attached document patch to document that '--'
comments are not passed to the server, while C-style block comments are.
We can call this a feature.  ;-)

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

  + Everyone has their own god. +