pg.ddx.io  pgsql-admin@postgresql.org mailing list archive  
help / color / mirror / Atom feed
postgres seems to ignore log_min_duration_statement
9+ messages / 5 participants
[nested] [flat]

* postgres seems to ignore log_min_duration_statement
@ 2008-10-14 09:23 Martin A. Brooks <martin@antibodymx.net>
  2008-10-14 10:14 ` Re: postgres seems to ignore log_min_duration_statement Guillaume Lelarge <guillaume@lelarge.info>
  2008-10-14 11:41 ` Re: postgres seems to ignore log_min_duration_statement Vladimir Rusinov <vladimir@greenmice.info>
  0 siblings, 2 replies; 9+ messages in thread

From: Martin A. Brooks @ 2008-10-14 09:23 UTC (permalink / raw)
  To: pgsql-admin

Hi

I want to have postgres log sql statements that take longer than 5 
seconds to execute.  In postgresql.conf I have set 
log_min_duration_statement as follows:

root@martin-desktop:/etc/postgresql/8.3/main# grep log_min_duration 
postgresql.conf
log_min_duration_statement = 5000       # -1 is disabled, 0 logs all 
statements

However, in the log files, I'm seeing entries for all SQL executed, not 
just that taking 5000ms or more. For example:

2008-10-14 10:15:50 BST PID:20349 DB:vhdb LOG:  statement: select * from 
vendors;
2008-10-14 10:15:50 BST PID:20349 DB:vhdb LOG:  duration: 0.259 ms
2008-10-14 10:15:50 BST PID:20349 DB:vhdb LOG:  QUERY STATISTICS
2008-10-14 10:15:50 BST PID:20349 DB:vhdb DETAIL:  ! system usage stats:
        !       0.000281 elapsed 0.000000 user 0.000000 system sec
        !       [0.004000 user 0.004000 sys total]
        !       0/0 [0/176] filesystem blocks in/out
        !       0/0 [0/923] page faults/reclaims, 0 [0] swaps
        !       0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent
        !       0/0 [8/0] voluntary/involuntary context switches
        ! buffer usage stats:
        !       Shared blocks:          0 read,          0 written, 
buffer hit rate = 100.00%
        !       Local  blocks:          0 read,          0 written, 
buffer hit rate = 0.00%
        !       Direct blocks:          0 read,          0 written


Am I missing something obvious?

Regards

-- 
Martin A. Brooks |  http://www.antibodymx.net/ | Anti-spam & anti-virus
   Consultant    |  martin@antibodymx.net      | filtering. Inoculate
 antibodymx.net  |  m: +447792493388           | your mail system.




^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: postgres seems to ignore log_min_duration_statement
  2008-10-14 09:23 postgres seems to ignore log_min_duration_statement Martin A. Brooks <martin@antibodymx.net>
@ 2008-10-14 10:14 ` Guillaume Lelarge <guillaume@lelarge.info>
  2008-10-14 10:30   ` Re: postgres seems to ignore log_min_duration_statement Martin A. Brooks <martin@antibodymx.net>
  1 sibling, 1 reply; 9+ messages in thread

From: Guillaume Lelarge @ 2008-10-14 10:14 UTC (permalink / raw)
  To: Martin A. Brooks <martin@antibodymx.net>; +Cc: pgsql-admin

Martin A. Brooks a écrit :
> Hi
> 
> I want to have postgres log sql statements that take longer than 5
> seconds to execute.  In postgresql.conf I have set
> log_min_duration_statement as follows:
> 
> root@martin-desktop:/etc/postgresql/8.3/main# grep log_min_duration
> postgresql.conf
> log_min_duration_statement = 5000       # -1 is disabled, 0 logs all
> statements
> 
> However, in the log files, I'm seeing entries for all SQL executed, not
> just that taking 5000ms or more. For example:
> 
> 2008-10-14 10:15:50 BST PID:20349 DB:vhdb LOG:  statement: select * from
> vendors;
> 2008-10-14 10:15:50 BST PID:20349 DB:vhdb LOG:  duration: 0.259 ms
> 2008-10-14 10:15:50 BST PID:20349 DB:vhdb LOG:  QUERY STATISTICS
> 2008-10-14 10:15:50 BST PID:20349 DB:vhdb DETAIL:  ! system usage stats:
>        !       0.000281 elapsed 0.000000 user 0.000000 system sec
>        !       [0.004000 user 0.004000 sys total]
>        !       0/0 [0/176] filesystem blocks in/out
>        !       0/0 [0/923] page faults/reclaims, 0 [0] swaps
>        !       0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent
>        !       0/0 [8/0] voluntary/involuntary context switches
>        ! buffer usage stats:
>        !       Shared blocks:          0 read,          0 written,
> buffer hit rate = 100.00%
>        !       Local  blocks:          0 read,          0 written,
> buffer hit rate = 0.00%
>        !       Direct blocks:          0 read,          0 written
> 

This last log is enabled with the log_statement_stats parameter. Set it
to off to disable it.


-- 
Guillaume.
 http://www.postgresqlfr.org
 http://dalibo.com



^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: postgres seems to ignore log_min_duration_statement
  2008-10-14 09:23 postgres seems to ignore log_min_duration_statement Martin A. Brooks <martin@antibodymx.net>
  2008-10-14 10:14 ` Re: postgres seems to ignore log_min_duration_statement Guillaume Lelarge <guillaume@lelarge.info>
@ 2008-10-14 10:30   ` Martin A. Brooks <martin@antibodymx.net>
  2008-10-14 11:20     ` Re: postgres seems to ignore log_min_duration_statement Guillaume Lelarge <guillaume@lelarge.info>
  0 siblings, 1 reply; 9+ messages in thread

From: Martin A. Brooks @ 2008-10-14 10:30 UTC (permalink / raw)
  To: Guillaume Lelarge <guillaume@lelarge.info>; +Cc: pgsql-admin

Guillaume Lelarge wrote:
> Martin A. Brooks a écrit :
>   
>> However, in the log files, I'm seeing entries for all SQL executed, not
>> just that taking 5000ms or more. For example:
>>
>> 2008-10-14 10:15:50 BST PID:20349 DB:vhdb LOG:  statement: select * from
>> vendors;
>> 2008-10-14 10:15:50 BST PID:20349 DB:vhdb LOG:  duration: 0.259 ms
>> 2008-10-14 10:15:50 BST PID:20349 DB:vhdb LOG:  QUERY STATISTICS
>> 2008-10-14 10:15:50 BST PID:20349 DB:vhdb DETAIL:  ! system usage stats:
>>        !       0.000281 elapsed 0.000000 user 0.000000 system sec
>>        !       [0.004000 user 0.004000 sys total]
>>        !       0/0 [0/176] filesystem blocks in/out
>>        !       0/0 [0/923] page faults/reclaims, 0 [0] swaps
>>        !       0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent
>>        !       0/0 [8/0] voluntary/involuntary context switches
>>        ! buffer usage stats:
>>        !       Shared blocks:          0 read,          0 written,
>> buffer hit rate = 100.00%
>>        !       Local  blocks:          0 read,          0 written,
>> buffer hit rate = 0.00%
>>        !       Direct blocks:          0 read,          0 written
>>
>>     
>
> This last log is enabled with the log_statement_stats parameter. Set it
> to off to disable it.
>
>   

I _want_ the stats, however I _only_ want the stats for queries taking 
over 5 seconds.


-- 
Martin A. Brooks |  http://www.antibodymx.net/ | Anti-spam & anti-virus
   Consultant    |  martin@antibodymx.net      | filtering. Inoculate
 antibodymx.net  |  m: +447792493388           | your mail system.




^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: postgres seems to ignore log_min_duration_statement
  2008-10-14 09:23 postgres seems to ignore log_min_duration_statement Martin A. Brooks <martin@antibodymx.net>
  2008-10-14 10:14 ` Re: postgres seems to ignore log_min_duration_statement Guillaume Lelarge <guillaume@lelarge.info>
  2008-10-14 10:30   ` Re: postgres seems to ignore log_min_duration_statement Martin A. Brooks <martin@antibodymx.net>
@ 2008-10-14 11:20     ` Guillaume Lelarge <guillaume@lelarge.info>
  2008-10-14 11:26       ` Re: postgres seems to ignore log_min_duration_statement Martin A. Brooks <martin@antibodymx.net>
  0 siblings, 1 reply; 9+ messages in thread

From: Guillaume Lelarge @ 2008-10-14 11:20 UTC (permalink / raw)
  To: Martin A. Brooks <martin@antibodymx.net>; +Cc: pgsql-admin

Martin A. Brooks a écrit :
> Guillaume Lelarge wrote:
>> Martin A. Brooks a écrit :
>>  
>>> However, in the log files, I'm seeing entries for all SQL executed, not
>>> just that taking 5000ms or more. For example:
>>>
>>> 2008-10-14 10:15:50 BST PID:20349 DB:vhdb LOG:  statement: select * from
>>> vendors;
>>> 2008-10-14 10:15:50 BST PID:20349 DB:vhdb LOG:  duration: 0.259 ms
>>> 2008-10-14 10:15:50 BST PID:20349 DB:vhdb LOG:  QUERY STATISTICS
>>> 2008-10-14 10:15:50 BST PID:20349 DB:vhdb DETAIL:  ! system usage stats:
>>>        !       0.000281 elapsed 0.000000 user 0.000000 system sec
>>>        !       [0.004000 user 0.004000 sys total]
>>>        !       0/0 [0/176] filesystem blocks in/out
>>>        !       0/0 [0/923] page faults/reclaims, 0 [0] swaps
>>>        !       0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent
>>>        !       0/0 [8/0] voluntary/involuntary context switches
>>>        ! buffer usage stats:
>>>        !       Shared blocks:          0 read,          0 written,
>>> buffer hit rate = 100.00%
>>>        !       Local  blocks:          0 read,          0 written,
>>> buffer hit rate = 0.00%
>>>        !       Direct blocks:          0 read,          0 written
>>>
>>>     
>>
>> This last log is enabled with the log_statement_stats parameter. Set it
>> to off to disable it.
>>
>>   
> 
> I _want_ the stats, however I _only_ want the stats for queries taking
> over 5 seconds.
> 

Well, AFAIK, you can't.


-- 
Guillaume.
 http://www.postgresqlfr.org
 http://dalibo.com



^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: postgres seems to ignore log_min_duration_statement
  2008-10-14 09:23 postgres seems to ignore log_min_duration_statement Martin A. Brooks <martin@antibodymx.net>
  2008-10-14 10:14 ` Re: postgres seems to ignore log_min_duration_statement Guillaume Lelarge <guillaume@lelarge.info>
  2008-10-14 10:30   ` Re: postgres seems to ignore log_min_duration_statement Martin A. Brooks <martin@antibodymx.net>
  2008-10-14 11:20     ` Re: postgres seems to ignore log_min_duration_statement Guillaume Lelarge <guillaume@lelarge.info>
@ 2008-10-14 11:26       ` Martin A. Brooks <martin@antibodymx.net>
  0 siblings, 0 replies; 9+ messages in thread

From: Martin A. Brooks @ 2008-10-14 11:26 UTC (permalink / raw)
  To: Guillaume Lelarge <guillaume@lelarge.info>; +Cc: pgsql-admin

Guillaume Lelarge wrote:
> Martin A. Brooks a écrit :
>   
>> I _want_ the stats, however I _only_ want the stats for queries taking
>> over 5 seconds.
>>
>>     
>
> Well, AFAIK, you can't.
>   

Then that would seem to entirely negate the point of having the 
log_min_duration_statement option, from what I can see in the docs.


-- 
Martin A. Brooks |  http://www.antibodymx.net/ | Anti-spam & anti-virus
   Consultant    |  martin@antibodymx.net      | filtering. Inoculate
 antibodymx.net  |  m: +447792493388           | your mail system.




^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: postgres seems to ignore log_min_duration_statement
  2008-10-14 09:23 postgres seems to ignore log_min_duration_statement Martin A. Brooks <martin@antibodymx.net>
@ 2008-10-14 11:41 ` Vladimir Rusinov <vladimir@greenmice.info>
  2008-10-14 11:48   ` Re: postgres seems to ignore log_min_duration_statement Martin A. Brooks <martin@antibodymx.net>
  1 sibling, 1 reply; 9+ messages in thread

From: Vladimir Rusinov @ 2008-10-14 11:41 UTC (permalink / raw)
  To: Martin A. Brooks <martin@antibodymx.net>; +Cc: pgsql-admin

On Tue, Oct 14, 2008 at 1:23 PM, Martin A. Brooks <martin@antibodymx.net>wrote:

> Hi
>
> I want to have postgres log sql statements that take longer than 5 seconds
> to execute.  In postgresql.conf I have set log_min_duration_statement as
> follows:
>
> root@martin-desktop:/etc/postgresql/8.3/main# grep log_min_duration
> postgresql.conf
> log_min_duration_statement = 5000       # -1 is disabled, 0 logs all
> statements



May be you have log_min_messages = debug?
Please, show full logging section.


-- 
Vladimir Rusinov
http://greenmice.info/

^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: postgres seems to ignore log_min_duration_statement
  2008-10-14 09:23 postgres seems to ignore log_min_duration_statement Martin A. Brooks <martin@antibodymx.net>
  2008-10-14 11:41 ` Re: postgres seems to ignore log_min_duration_statement Vladimir Rusinov <vladimir@greenmice.info>
@ 2008-10-14 11:48   ` Martin A. Brooks <martin@antibodymx.net>
  2008-10-14 12:56     ` Re: postgres seems to ignore log_min_duration_statement Tom Lane <tgl@sss.pgh.pa.us>
  0 siblings, 1 reply; 9+ messages in thread

From: Martin A. Brooks @ 2008-10-14 11:48 UTC (permalink / raw)
  To: Vladimir Rusinov <vladimir@greenmice.info>; +Cc: pgsql-admin

Vladimir Rusinov wrote:
> May be you have log_min_messages = debug?
> Please, show full logging section.

I don't explicitly set that parameter in my config.  The full config 
file can be found at  http://www.antibodymx.net/postgresql.conf

Thanks

-- 
Martin A. Brooks |  http://www.antibodymx.net/ | Anti-spam & anti-virus
   Consultant    |  martin@antibodymx.net      | filtering. Inoculate
 antibodymx.net  |  m: +447792493388           | your mail system.




^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: postgres seems to ignore log_min_duration_statement
  2008-10-14 09:23 postgres seems to ignore log_min_duration_statement Martin A. Brooks <martin@antibodymx.net>
  2008-10-14 11:41 ` Re: postgres seems to ignore log_min_duration_statement Vladimir Rusinov <vladimir@greenmice.info>
  2008-10-14 11:48   ` Re: postgres seems to ignore log_min_duration_statement Martin A. Brooks <martin@antibodymx.net>
@ 2008-10-14 12:56     ` Tom Lane <tgl@sss.pgh.pa.us>
  2008-10-16 02:17       ` Re: postgres seems to ignore log_min_duration_statement Bruce Momjian <bruce@momjian.us>
  0 siblings, 1 reply; 9+ messages in thread

From: Tom Lane @ 2008-10-14 12:56 UTC (permalink / raw)
  To: Martin A. Brooks <martin@antibodymx.net>; +Cc: Vladimir Rusinov <vladimir@greenmice.info>; pgsql-admin

"Martin A. Brooks" <martin@antibodymx.net> writes:
> I don't explicitly set that parameter in my config.  The full config 
> file can be found at  http://www.antibodymx.net/postgresql.conf

You've got log_duration on; that overrides log_min_duration_statement
and forces statement durations to always be logged.

(No, I'm not quite sure why we have both variables ...)

			regards, tom lane



^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: postgres seems to ignore log_min_duration_statement
  2008-10-14 09:23 postgres seems to ignore log_min_duration_statement Martin A. Brooks <martin@antibodymx.net>
  2008-10-14 11:41 ` Re: postgres seems to ignore log_min_duration_statement Vladimir Rusinov <vladimir@greenmice.info>
  2008-10-14 11:48   ` Re: postgres seems to ignore log_min_duration_statement Martin A. Brooks <martin@antibodymx.net>
  2008-10-14 12:56     ` Re: postgres seems to ignore log_min_duration_statement Tom Lane <tgl@sss.pgh.pa.us>
@ 2008-10-16 02:17       ` Bruce Momjian <bruce@momjian.us>
  0 siblings, 0 replies; 9+ messages in thread

From: Bruce Momjian @ 2008-10-16 02:17 UTC (permalink / raw)
  To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Martin A. Brooks <martin@antibodymx.net>; Vladimir Rusinov <vladimir@greenmice.info>; pgsql-admin

Tom Lane wrote:
> "Martin A. Brooks" <martin@antibodymx.net> writes:
> > I don't explicitly set that parameter in my config.  The full config 
> > file can be found at  http://www.antibodymx.net/postgresql.conf
> 
> You've got log_duration on; that overrides log_min_duration_statement
> and forces statement durations to always be logged.
> 
> (No, I'm not quite sure why we have both variables ...)

I believe log_duration prints just the duration and assumes you printed
the statement previously (when it arrived).  log_min_duration_statement
by definition has to print after the statement completes.

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

  + If your life is a hard drive, Christ can be your backup. +



^ permalink  raw  reply  [nested|flat] 9+ messages in thread


end of thread, other threads:[~2008-10-16 02:17 UTC | newest]

Thread overview: 9+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2008-10-14 09:23 postgres seems to ignore log_min_duration_statement Martin A. Brooks <martin@antibodymx.net>
2008-10-14 10:14 ` Guillaume Lelarge <guillaume@lelarge.info>
2008-10-14 10:30   ` Martin A. Brooks <martin@antibodymx.net>
2008-10-14 11:20     ` Guillaume Lelarge <guillaume@lelarge.info>
2008-10-14 11:26       ` Martin A. Brooks <martin@antibodymx.net>
2008-10-14 11:41 ` Vladimir Rusinov <vladimir@greenmice.info>
2008-10-14 11:48   ` Martin A. Brooks <martin@antibodymx.net>
2008-10-14 12:56     ` Tom Lane <tgl@sss.pgh.pa.us>
2008-10-16 02:17       ` Bruce Momjian <bruce@momjian.us>

This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox