Re: four minor proposals for 9.5

2014-04-04 6:51 GMT+02:00 Amit Kapila <amit(dot)kapila16(at)gmail(dot)com>:

> On Tue, Apr 1, 2014 at 11:42 PM, Pavel Stehule <pavel(dot)stehule(at)gmail(dot)com>
> wrote:
> > 2014-03-27 17:56 GMT+01:00 Pavel Stehule <pavel(dot)stehule(at)gmail(dot)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.
>

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.

> 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?
>

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

%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

I expect, so almost all infrastructure is done - and I don't expect
significant changes.

>
> 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.

Regards

Pavel

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