2014-04-04 6:51 GMT+02:00 Amit Kapila <amit.kapil...@gmail.com>: > On Tue, Apr 1, 2014 at 11:42 PM, Pavel Stehule <pavel.steh...@gmail.com> > wrote: > > 2014-03-27 17:56 GMT+01:00 Pavel Stehule <pavel.steh...@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. >
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 >