Thread: Log duration and statement for slow queries + limiting the number of log files generated

Hello,

I am trying to get postgres 8.4.4 to log the duration and statement of
queries that take longer than 200 ms. I played with the log settings
in postgresql.conf but I still see logs of durations of very fast
statements. Here is my current configuration:

log_min_duration_statement = 200
log_duration = on
log_line_prefix = '<%t> '
log_statement = 'all'

With this configuration I am still getting these in the log files:

<2011-09-02 14:47:19 EDT> LOG:  duration: 0.017 ms
<2011-09-02 14:47:19 EDT> LOG:  execute <unnamed>: SET SESSION
CHARACTERISTICS AS TRANSACTION READ WRITE
<2011-09-02 14:47:19 EDT> LOG:  duration: 0.004 ms
<2011-09-02 14:47:19 EDT> LOG:  duration: 0.014 ms
<2011-09-02 14:47:19 EDT> LOG:  duration: 0.017 ms
<2011-09-02 14:47:19 EDT> LOG:  execute <unnamed>: SET SESSION
CHARACTERISTICS AS TRANSACTION READ ONLY


How do I filter these out?

Also, how do I restrict the maximum number of log files generated to 2
with the assumption that they will roll over when filled?

Thanks,

Alec

On Fri, 2011-09-16 at 11:16 -0600, Alec Swan wrote:
> Hello,
>
> I am trying to get postgres 8.4.4 to log the duration and statement of
> queries that take longer than 200 ms. I played with the log settings
> in postgresql.conf but I still see logs of durations of very fast
> statements. Here is my current configuration:
>
> log_min_duration_statement = 200
> log_duration = on
> log_line_prefix = '<%t> '
> log_statement = 'all'
>
> With this configuration I am still getting these in the log files:
>
> <2011-09-02 14:47:19 EDT> LOG:  duration: 0.017 ms
> <2011-09-02 14:47:19 EDT> LOG:  execute <unnamed>: SET SESSION
> CHARACTERISTICS AS TRANSACTION READ WRITE
> <2011-09-02 14:47:19 EDT> LOG:  duration: 0.004 ms
> <2011-09-02 14:47:19 EDT> LOG:  duration: 0.014 ms
> <2011-09-02 14:47:19 EDT> LOG:  duration: 0.017 ms
> <2011-09-02 14:47:19 EDT> LOG:  execute <unnamed>: SET SESSION
> CHARACTERISTICS AS TRANSACTION READ ONLY
>
>
> How do I filter these out?
>

You should set log_duration to off, and log_statement to none.
log_min_duration_statement will take care of logging duration and
statement if the query duration is longer than 200 ms.

> Also, how do I restrict the maximum number of log files generated to 2
> with the assumption that they will roll over when filled?
>

You can't do that with PostgreSQL configuration. You need another tool,
such as logrotate.


--
Guillaume
  http://blog.guillaume.lelarge.info
  http://www.dalibo.com


On 16 September 2011 18:16, Alec Swan <alecswan@gmail.com> wrote:
> Hello,
>
> I am trying to get postgres 8.4.4 to log the duration and statement of
> queries that take longer than 200 ms. I played with the log settings
> in postgresql.conf but I still see logs of durations of very fast
> statements. Here is my current configuration:
>
> log_min_duration_statement = 200
> log_duration = on
> log_line_prefix = '<%t> '
> log_statement = 'all'
>
> With this configuration I am still getting these in the log files:
>
> <2011-09-02 14:47:19 EDT> LOG:  duration: 0.017 ms
> <2011-09-02 14:47:19 EDT> LOG:  execute <unnamed>: SET SESSION
> CHARACTERISTICS AS TRANSACTION READ WRITE
> <2011-09-02 14:47:19 EDT> LOG:  duration: 0.004 ms
> <2011-09-02 14:47:19 EDT> LOG:  duration: 0.014 ms
> <2011-09-02 14:47:19 EDT> LOG:  duration: 0.017 ms
> <2011-09-02 14:47:19 EDT> LOG:  execute <unnamed>: SET SESSION
> CHARACTERISTICS AS TRANSACTION READ ONLY
>
>
> How do I filter these out?

You have log_statement set to 'all', and since it's mostly independent
of log_min_duration_statement, it's logging everything anyway.  You
may wish to just set log_statement to 'none'.

> Also, how do I restrict the maximum number of log files generated to 2
> with the assumption that they will roll over when filled?

--
Thom Brown
Twitter: @darkixion
IRC (freenode): dark_ixion
Registered Linux user: #516935

EnterpriseDB UK: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Thanks, I got duration logging to work the way I wanted. I will look
into logrotate next.

On Fri, Sep 16, 2011 at 11:22 AM, Thom Brown <thom@linux.com> wrote:
> On 16 September 2011 18:16, Alec Swan <alecswan@gmail.com> wrote:
>> Hello,
>>
>> I am trying to get postgres 8.4.4 to log the duration and statement of
>> queries that take longer than 200 ms. I played with the log settings
>> in postgresql.conf but I still see logs of durations of very fast
>> statements. Here is my current configuration:
>>
>> log_min_duration_statement = 200
>> log_duration = on
>> log_line_prefix = '<%t> '
>> log_statement = 'all'
>>
>> With this configuration I am still getting these in the log files:
>>
>> <2011-09-02 14:47:19 EDT> LOG:  duration: 0.017 ms
>> <2011-09-02 14:47:19 EDT> LOG:  execute <unnamed>: SET SESSION
>> CHARACTERISTICS AS TRANSACTION READ WRITE
>> <2011-09-02 14:47:19 EDT> LOG:  duration: 0.004 ms
>> <2011-09-02 14:47:19 EDT> LOG:  duration: 0.014 ms
>> <2011-09-02 14:47:19 EDT> LOG:  duration: 0.017 ms
>> <2011-09-02 14:47:19 EDT> LOG:  execute <unnamed>: SET SESSION
>> CHARACTERISTICS AS TRANSACTION READ ONLY
>>
>>
>> How do I filter these out?
>
> You have log_statement set to 'all', and since it's mostly independent
> of log_min_duration_statement, it's logging everything anyway.  You
> may wish to just set log_statement to 'none'.
>
>> Also, how do I restrict the maximum number of log files generated to 2
>> with the assumption that they will roll over when filled?
>
> --
> Thom Brown
> Twitter: @darkixion
> IRC (freenode): dark_ixion
> Registered Linux user: #516935
>
> EnterpriseDB UK: http://www.enterprisedb.com
> The Enterprise PostgreSQL Company
>