Обсуждение: postgres seems to ignore log_min_duration_statement
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.
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
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.
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
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.
On Tue, Oct 14, 2008 at 1:23 PM, Martin A. Brooks <martin@antibodymx.net> wrote:
May be you have log_min_messages = debug?
Please, show full logging section.
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/
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.
"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
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. +