Обсуждение: four minor proposals for 9.5

On 03/19/2014 04:34 PM, Pavel Stehule wrote:
> Hello
>
> I wrote a few patches, that we use in our production. These patches
> are small, but I hope, so its can be interesting for upstream:
>
> 1. cancel time - we log a execution time cancelled statements

+1

I even wrote a patch to do this, but it wasn't pretty so I never posted
it.  I would be happy to review yours or revive mine.

> 2. fatal verbose - this patch ensure a verbose log for fatal errors.
> It simplify a investigation about reasons of error.

+0

> 3. relation limit - possibility to set session limit for maximum size
> of relations. Any relation cannot be extended over this limit in
> session, when this value is higher than zero. Motivation - we use lot
> of queries like CREATE TABLE AS SELECT .. , and some very big results
> decreased a disk free space too much. It was high risk in our multi
> user environment. Motivation is similar like temp_files_limit.

-1

Also, I can't find any temp_files_limit setting anywhere.

> 4. track statement lock - we are able to track a locking time for
> query and print this data in slow query log and auto_explain log. It
> help to us with lather slow query log analysis.

-0

> Do you thinking so  these patches can be generally useful?

Yes and no, as scored above.

-- 
Vik

Pavel,

> I wrote a few patches, that we use in our production. These patches are
> small, but I hope, so its can be interesting for upstream:
> 
> 1. cancel time - we log a execution time cancelled statements

Manually cancelled?  statement_timeout?

Anyway, +1 to add the time to the existing log message, but not in an
additional log line.

BTW, what do folks think of the idea of adding a new log column called
"timing", which would record duration etc.?  It would be really nice not
to have to parse this out of the text message all the time ...

> 2. fatal verbose - this patch ensure a verbose log for fatal errors. It
> simplify a investigation about reasons of error.

Configurable, or not?

> 3. relation limit - possibility to set session limit for maximum size of
> relations. Any relation cannot be extended over this limit in session, when
> this value is higher than zero. Motivation - we use lot of queries like
> CREATE TABLE AS SELECT .. , and some very big results decreased a disk free
> space too much. It was high risk in our multi user environment. Motivation
> is similar like temp_files_limit.

I'd think the size of the relation you were creating would be difficult
to measure.  Also, would this apply to REINDEX/VACUUM FULL/ALTER?  Or
just CREATE TABLE AS/SELECT INTO?

> 4. track statement lock - we are able to track a locking time for query and
> print this data in slow query log and auto_explain log. It help to us with
> lather slow query log analysis.

I'm very interested in this.  What does it look like?

-- 
Josh Berkus
PostgreSQL Experts Inc.
http://pgexperts.com

On Wed, Mar 19, 2014 at 9:04 PM, Pavel Stehule <pavel.stehule@gmail.com> wrote:
> Hello
>
> I wrote a few patches, that we use in our production. These patches are
> small, but I hope, so its can be interesting for upstream:
>
> 1. cancel time - we log a execution time cancelled statements
>
> 2. fatal verbose - this patch ensure a verbose log for fatal errors. It
> simplify a investigation about reasons of error.
>
> 3. relation limit - possibility to set session limit for maximum size of
> relations. Any relation cannot be extended over this limit in session, when
> this value is higher than zero. Motivation - we use lot of queries like
> CREATE TABLE AS SELECT .. , and some very big results decreased a disk free
> space too much. It was high risk in our multi user environment. Motivation
> is similar like temp_files_limit.

So if there is error on reaching max threshold size, won't it loose all data or
is that expected?

Also I think it might not be applicable for all table inserts, as normally
checkpointer/bgrwriter flushes data, so you might not be able to estimate
size immediately when your SQL statement is executing.

Won't it better to have LIMIT Rows in Select statement or generically
have table level option for Max Rows?


With Regards,
Amit Kapila.
EnterpriseDB: http://www.enterprisedb.com

On 20/03/14 13:28, Josh Berkus wrote:

>> 3. relation limit - possibility to set session limit for maximum size of
>> relations. Any relation cannot be extended over this limit in session, when
>> this value is higher than zero. Motivation - we use lot of queries like
>> CREATE TABLE AS SELECT .. , and some very big results decreased a disk free
>> space too much. It was high risk in our multi user environment. Motivation
>> is similar like temp_files_limit.
>
> I'd think the size of the relation you were creating would be difficult
> to measure.  Also, would this apply to REINDEX/VACUUM FULL/ALTER?  Or
> just CREATE TABLE AS/SELECT INTO?
>

Also I think this would probably only make sense for TEMPORARY tables - 
otherwise you can get this sort of thing going on:

- you create a table and you have set a relation size limit
- you commit and keep working
- I add a whole lot of rows to your new table (taking it over the limit)
- you go to add some more rows to this table...

Should you now be stopped working? Does this feature need to track *who* 
added which chunks of a table (suspect very difficult to do sensibly)?

Regards

Mark

On 20/03/14 20:08, Pavel Stehule wrote:
>
>
>
> 2014-03-20 7:25 GMT+01:00 Mark Kirkwood <mark.kirkwood@catalyst.net.nz
>     Also I think this would probably only make sense for TEMPORARY
>     tables - otherwise you can get this sort of thing going on:
>
>     - you create a table and you have set a relation size limit
>     - you commit and keep working
>     - I add a whole lot of rows to your new table (taking it over the limit)
>     - you go to add some more rows to this table...
>
>
> you cannot to across session limit and is not important if you do
> inserts more times or once.
>

Sorry Pavel - what you have said above is difficult for me to understand 
- if the limit is intended as a *session* limit then concurrent activity 
from multiple sessions makes it behave - well - strangely to say the 
least, as tables are essentially shared resources.

Regards

Mark

On Tue, Apr 1, 2014 at 11:42 PM, Pavel Stehule <pavel.stehule@gmail.com> wrote:
> 2014-03-27 17:56 GMT+01:00 Pavel Stehule <pavel.stehule@gmail.com>:
>> So I'll prepare a some prototypes in next month for
>>
>> 1. log a execution time for cancelled queries,
>> 2. track a query lock time
>>
>
> When I though about this proposal, I found so our implementation is
> plus/minus hack, that can works well in GoodData, but can be inconsistent
> with native postgresql. So in this proposal I'll plan some different than we
> use, but I hope so it is more consistent with upstream.
>
> So I miss a execution time for cancelled queries. Same time can be
> interesting for some queries that was from any reasons - temp file limits
> can stop queries after 5 minutes, some out of memory etc ..
>
> It is not hard to implement printing duration for cancelled queries, but is
> impossible do it for any kind of exception. But there is way. We can use a
> "log line prefix" space. Now, there are not a possibility to print duration
> - so we can introduce a new symbol %D as duration.

This means for any exception/error it will print duration if %D is used, not
only for cancelled queries or you planing just for some specific logs like
when query is cancelled.
One more thing I think currently also we can find that by crude way
(pg_stat_activity has query_start time and log_line_prefix has end time),
but I think the having in one place 'log' will be more useful.


> Same technique I would to
> use for printing lock time - it can be printing instead symbol %L.

Above you have mentioned that you are planing to have three different
lock times (Table, Tuple and others), so will this one symbol (%L) enable
all three lock times?
Are you planing to add new logs for logging this or planing to use existing
infrastructure?

One general point is that won't it be bit difficult to parse the log line having
so many times, should we consider to log with some special marker for
each time (for example: tup_lock_wait_time:1000ms).


With Regards,
Amit Kapila.
EnterpriseDB: http://www.enterprisedb.com

On Mon, Apr 7, 2014 at 12:16 AM, Pavel Stehule <pavel.stehule@gmail.com> wrote:
> 2014-04-04 6:51 GMT+02:00 Amit Kapila <amit.kapila16@gmail.com>:
>> On Tue, Apr 1, 2014 at 11:42 PM, Pavel Stehule <pavel.stehule@gmail.com>
>> wrote:
>> > 2014-03-27 17:56 GMT+01:00 Pavel Stehule <pavel.stehule@gmail.com>:
>> >> So I'll prepare a some prototypes in next month for
>> >>
>> >> 1. log a execution time for cancelled queries,
>> >> 2. track a query lock time
> Yes. Initially I though only about cancelled queries, but now O am thinking
> so some more wide solution can be better. Sometimes - some long queries can
> be stopped by Postgres, or by system - and info about duration can be same
> usefull.

Right.

>>
>> One more thing I think currently also we can find that by crude way
>> (pg_stat_activity has query_start time and log_line_prefix has end time),
>> but I think the having in one place 'log' will be more useful.
> ??

I just wanted to say that if someone wants to calculate the duration
of cancelled query (or other error'd query), you can do that by checking
the start time from pg_stat_activity and end time from log (using
log_line_prefix), but this is of course cumbersome.

>> > Same technique I would to
>> > use for printing lock time - it can be printing instead symbol %L.
>>
>> Above you have mentioned that you are planing to have three different
>> lock times (Table, Tuple and others), so will this one symbol (%L) enable
>> all three lock times?
>
>
> My idea is start with %L as total lock time, what is useful for wide group
> of users, and next or in same time we can enhance it with two chars prefix
> symbols

So do you want to just print lock time for error'd statements, won't
it better to
do it for non-error'd statements as well or rather I feel it can be more useful
for non-error statements? Do we already have some easy way to get wait-time
for non-error statements?

> so
>
> %L .. total lock time
> %Lr .. lock relation
> %Lt .. lock tuples
> %Lo .. lock others
>
> L = Lr + Lt + Lr
>
>>
>> Are you planing to add new logs for logging this or planing to use
>> existing
>> infrastructure?
>
>
> I have not a prototype yet, so I don't know what will be necessary

Okay, I think then it's better to discuss after your initial analysis/
prototype, but I think you might need to add some infrastructure code
to make it possible, as lock database object (relation, tuple, ..) and lock
others (buffers, ..) have different locking strategy, so to get total wait time
for a statement due to different kind of locks you need to accumulate
different wait times.

>> One general point is that won't it be bit difficult to parse the log line
>> having
>> so many times, should we consider to log with some special marker for
>> each time (for example: tup_lock_wait_time:1000ms).
>
>
> We should to optimize a log_line_prefix processing instead.
>
> Proposed options are interesting for "enterprise" using, when you have a
> some more smart tools for log entry processing, and when you need a complex
> view about performance of billions queries - when cancel time and lock time
> is important piece in mosaic of server' fitness.

Exactly, though this might not be directly related to this patch, but having
it would be useful.

With Regards,
Amit Kapila.
EnterpriseDB: http://www.enterprisedb.com

On 4/6/14 2:46 PM, Pavel Stehule wrote:
>
> Proposed options are interesting for "enterprise" using, when you have 
> a some more smart tools for log entry processing, and when you need a 
> complex view about performance of billions queries - when cancel time 
> and lock time is important piece in mosaic of server' fitness.

I once sent a design proposal over for something I called "Performance 
Events" that included this.  It will be difficult to get everything 
people want to track into log_line_prefix macro form.  You're right that 
this particular one can probably be pushed into there, but you're adding 
four macros just for this feature. And that's only a fraction of what 
people expect from database per-query performance metrics.

The problem I got stuck on with the performance event project was where 
to store the data collected.  If you want to keep up with read rates, 
you can't use the existing log infrastructure.  It has to be something 
faster, lighter.  I wanted to push the data into shared memory somewhere 
instead.  Then some sort of logging consumer could drain that queue and 
persist it to disk.

Since then, we've had a number of advances, particularly these two:

-Dynamic shared memory allocation.
-Query log data from pg_stat_statements can persist.

With those important fundamentals available, I'm wandering around right 
now trying to get development resources to pick the whole event logging 
idea up again.  The hardest parts of the infrastructure I was stuck on 
in the past are in the code today.

-- 
Greg Smith greg.smith@crunchydatasolutions.com
Chief PostgreSQL Evangelist - http://crunchydatasolutions.com/

On Tue, Apr 8, 2014 at 9:07 PM, Pavel Stehule <pavel.stehule@gmail.com> wrote:
> 2014-04-08 6:27 GMT+02:00 Amit Kapila <amit.kapila16@gmail.com>:
>> So do you want to just print lock time for error'd statements, won't
>> it better to
>> do it for non-error'd statements as well or rather I feel it can be more
>> useful
>> for non-error statements? Do we already have some easy way to get
>> wait-time
>> for non-error statements?
>
>
> There are two points:
>
> a) we have no a some infrastructure how to glue some specific info to any
> query other than log_line_prefix.

Can't we do that by using log_duration and log_min_duration_statement?
For Example, if I enable these parameters, below is the log:

LOG:  duration: 343.000 ms  statement: create table t1(c1 int);

> And I have no any idea, how and what
> implement better. And I don't think so any new infrastructure (mechanism) is
> necessary. log_line_prefix increase log size, but it is very well parseable
> - splunk and similar sw has no problem with it.

One thing that could happen if we implement total lock time at
log_line_prefix is that if user enables log_lock_waits, then it will start
printing duration for each lock wait time, not sure again it depends on
implementation.

> b) lock time can be interesting on error statements too - for example - you
> can cancel locked queries - so you would to see a lock time and duration for
> cancelled queries. So this implementation can be sensible too.

Agreed, I just said it will be quite useful for non-error'd long running
statements as well, so it might be good idea to see if we can implement
it for successful statements as well.


With Regards,
Amit Kapila.
EnterpriseDB: http://www.enterprisedb.com

On Tue, Apr 8, 2014 at 12:34 PM, Gregory Smith <gregsmithpgsql@gmail.com> wrote:
> On 4/6/14 2:46 PM, Pavel Stehule wrote:
>> Proposed options are interesting for "enterprise" using, when you have a
>> some more smart tools for log entry processing, and when you need a complex
>> view about performance of billions queries - when cancel time and lock time
>> is important piece in mosaic of server' fitness.
>
> I once sent a design proposal over for something I called "Performance
> Events" that included this.  It will be difficult to get everything people
> want to track into log_line_prefix macro form.  You're right that this
> particular one can probably be pushed into there, but you're adding four
> macros just for this feature. And that's only a fraction of what people
> expect from database per-query performance metrics.

I agree.  I don't think the idea of pushing this into the
log_line_prefix stuff as a one-off is a very good one.  Sure, we could
wedge it in there, but we've got an existing precedent that everything
that you can get with log_line_prefix also shows up in the CSV output
file.  And it's easy to imagine LOTS more counters that somebody might
want to have.  Time spent planning, time spent executing, time spent
waiting for disk I/O, time spent returning results to client, and I'm
sure people will think of many others.  I think this will balloon out
of control if we don't have a more systematic design for this sort of
thing.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Pavel Stehule <pavel.stehule@gmail.com> writes:
> 2014-04-14 14:57 GMT+02:00 Robert Haas <robertmhaas@gmail.com>:
>> I agree.  I don't think the idea of pushing this into the
>> log_line_prefix stuff as a one-off is a very good one.  Sure, we could
>> wedge it in there, but we've got an existing precedent that everything
>> that you can get with log_line_prefix also shows up in the CSV output
>> file.  And it's easy to imagine LOTS more counters that somebody might
>> want to have.

I think this argument is sufficient to kill this line of proposal
entirely.
        regards, tom lane

On Mon, Apr 14, 2014 at 6:27 PM, Robert Haas <robertmhaas@gmail.com> wrote:
> I agree.  I don't think the idea of pushing this into the
> log_line_prefix stuff as a one-off is a very good one.  Sure, we could
> wedge it in there, but we've got an existing precedent that everything
> that you can get with log_line_prefix also shows up in the CSV output
> file.  And it's easy to imagine LOTS more counters that somebody might
> want to have.  Time spent planning, time spent executing, time spent
> waiting for disk I/O, time spent returning results to client, and I'm
> sure people will think of many others.  I think this will balloon out
> of control if we don't have a more systematic design for this sort of
> thing.

Can't we think of some infrastructure similar to what is done for
log_duration and log_min_duration_statement?
Current it prints like below:
LOG:  duration: 343.000 ms  statement: create table t1(c1 int);

Let us say if user wants to track lock wait time a statement has
spent, then enable some config parameter (either log_lock_duration
or some other convenient way)

LOG:  lock duration: 'x' ms  statement: create table t1(c1 int);

With Regards,
Amit Kapila.
EnterpriseDB: http://www.enterprisedb.com

Pavel Stehule <pavel.stehule@gmail.com> writes:
> We can introduce new feature without hard dependency on CSV format

Look, the long and the short of it is that there is not consensus
that this measurement is worth creating a new CSV log column for.
And from that, there is also not consensus that it's worth putting
into log_line_prefix.  Therefore, this proposal is dead.  Please
stop prolonging the argument.
        regards, tom lane