OK, patch applied. I adjusted the documentation to not mention the
maximum (seemed unnecessary). I also adjusted the output to be clearer
by placing the duration at the start, with no 'sec' legend:
LOG: duration_statement: 0.020185 select * from pg_language, pg_class;
---------------------------------------------------------------------------
Christopher Kings-Lynne wrote:
> OK,
>
> This limits max value to INT_MAX / 1000.
>
> Chris
[ Attachment, skipping... ]
>
> ---------------------------(end of broadcast)---------------------------
> TIP 3: if posting/reading through Usenet, please send an appropriate
> subscribe-nomail command to majordomo@postgresql.org so that your
> message can get through to the mailing list cleanly
--
Bruce Momjian | http://candle.pha.pa.us
pgman@candle.pha.pa.us | (610) 359-1001
+ If your life is a hard drive, | 13 Roberts Road
+ Christ can be your backup. | Newtown Square, Pennsylvania 19073
Index: doc/src/sgml/runtime.sgml
===================================================================
RCS file: /cvsroot/pgsql-server/doc/src/sgml/runtime.sgml,v
retrieving revision 1.182
diff -c -c -r1.182 runtime.sgml
*** doc/src/sgml/runtime.sgml 27 May 2003 17:49:45 -0000 1.182
--- doc/src/sgml/runtime.sgml 11 Jun 2003 17:51:45 -0000
***************
*** 1052,1057 ****
--- 1052,1074 ----
</varlistentry>
<varlistentry>
+ <term><varname>LOG_MIN_DURATION_STATEMENT</varname> (<type>integer</type>)</term>
+ <listitem>
+ <para>
+ Sets a minimum statement execution time (in milliseconds)
+ above which a statement will be logged. All SQL statements
+ that run longer than the time specified will be logged together
+ with the duration, in seconds. The default is <literal>0</literal>
+ (turning this feature off). For example, if you set it
+ to <literal>250</literal> then all SQL statements that run longer
+ than 250ms will be logged along with the duration. Enabling this
+ option can be useful in tracking down unoptimized queries in
+ your applications.
+ </para>
+ </listitem>
+ </varlistentry>
+
+ <varlistentry>
<term><varname>LOG_MIN_ERROR_STATEMENT</varname> (<type>string</type>)</term>
<listitem>
<para>
Index: src/backend/tcop/postgres.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/tcop/postgres.c,v
retrieving revision 1.346
diff -c -c -r1.346 postgres.c
*** src/backend/tcop/postgres.c 27 May 2003 17:49:46 -0000 1.346
--- src/backend/tcop/postgres.c 11 Jun 2003 17:51:48 -0000
***************
*** 663,668 ****
--- 663,669 ----
struct timeval start_t,
stop_t;
bool save_log_duration = log_duration;
+ int save_log_min_duration_statement = log_min_duration_statement;
bool save_log_statement_stats = log_statement_stats;
/*
***************
*** 673,683 ****
pgstat_report_activity(query_string);
/*
! * We use save_log_duration so "SET log_duration = true" doesn't
! * report incorrect time because gettimeofday() wasn't called.
* Similarly, log_statement_stats has to be captured once.
*/
! if (save_log_duration)
gettimeofday(&start_t, NULL);
if (save_log_statement_stats)
--- 674,685 ----
pgstat_report_activity(query_string);
/*
! * We use save_log_* so "SET log_duration = true" and
! * "SET log_min_duration_statement = true" don't report incorrect
! * time because gettimeofday() wasn't called.
* Similarly, log_statement_stats has to be captured once.
*/
! if (save_log_duration || save_log_min_duration_statement > 0)
gettimeofday(&start_t, NULL);
if (save_log_statement_stats)
***************
*** 915,933 ****
QueryContext = NULL;
/*
! * Finish up monitoring.
*/
! if (save_log_duration)
{
gettimeofday(&stop_t, NULL);
if (stop_t.tv_usec < start_t.tv_usec)
{
stop_t.tv_sec--;
stop_t.tv_usec += 1000000;
}
! elog(LOG, "duration: %ld.%06ld sec",
! (long) (stop_t.tv_sec - start_t.tv_sec),
! (long) (stop_t.tv_usec - start_t.tv_usec));
}
if (save_log_statement_stats)
--- 917,954 ----
QueryContext = NULL;
/*
! * Combine processing here as we need to calculate the query
! * duration in both instances.
*/
! if (save_log_duration || save_log_min_duration_statement > 0)
{
+ long usecs;
gettimeofday(&stop_t, NULL);
if (stop_t.tv_usec < start_t.tv_usec)
{
stop_t.tv_sec--;
stop_t.tv_usec += 1000000;
}
! usecs = (long) (stop_t.tv_sec - start_t.tv_sec) * 1000000 + (long) (stop_t.tv_usec - start_t.tv_usec);
!
! /*
! * Output a duration_query to the log if the query has exceeded the
! * min duration.
! */
! if (usecs >= save_log_min_duration_statement * 1000)
! elog(LOG, "duration_statement: %ld.%06ld %s",
! (long) (stop_t.tv_sec - start_t.tv_sec),
! (long) (stop_t.tv_usec - start_t.tv_usec),
! query_string);
!
! /*
! * If the user is requesting logging of all durations, then log
! * that as well.
! */
! if (save_log_duration)
! elog(LOG, "duration: %ld.%06ld sec",
! (long) (stop_t.tv_sec - start_t.tv_sec),
! (long) (stop_t.tv_usec - start_t.tv_usec));
}
if (save_log_statement_stats)
Index: src/backend/utils/misc/guc.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/utils/misc/guc.c,v
retrieving revision 1.128
diff -c -c -r1.128 guc.c
*** src/backend/utils/misc/guc.c 11 Jun 2003 05:04:51 -0000 1.128
--- src/backend/utils/misc/guc.c 11 Jun 2003 17:51:52 -0000
***************
*** 55,60 ****
--- 55,62 ----
#include "utils/pg_locale.h"
#include "pgstat.h"
+ int log_min_duration_statement = 0;
+
#ifndef PG_KRB_SRVTAB
#define PG_KRB_SRVTAB ""
***************
*** 733,738 ****
--- 735,745 ----
{
{"extra_float_digits", PGC_USERSET}, &extra_float_digits,
0, -15, 2, NULL, NULL
+ },
+
+ {
+ {"log_min_duration_statement", PGC_USERSET}, &log_min_duration_statement,
+ 0, 0, INT_MAX / 1000, NULL, NULL
},
{
Index: src/backend/utils/misc/postgresql.conf.sample
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/utils/misc/postgresql.conf.sample,v
retrieving revision 1.79
diff -c -c -r1.79 postgresql.conf.sample
*** src/backend/utils/misc/postgresql.conf.sample 11 Jun 2003 05:04:51 -0000 1.79
--- src/backend/utils/misc/postgresql.conf.sample 11 Jun 2003 17:51:52 -0000
***************
*** 140,145 ****
--- 140,149 ----
# debug5, debug4, debug3, debug2, debug1,
# info, notice, warning, error, panic(off)
+ #log_min_duration_statement = 0 # Log all statements whose
+ # execution time exceeds the value, in
+ # milliseconds. Zero disables.
+
#debug_print_parse = false
#debug_print_rewritten = false
#debug_print_plan = false
Index: src/bin/psql/tab-complete.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/bin/psql/tab-complete.c,v
retrieving revision 1.77
diff -c -c -r1.77 tab-complete.c
*** src/bin/psql/tab-complete.c 14 May 2003 03:26:02 -0000 1.77
--- src/bin/psql/tab-complete.c 11 Jun 2003 17:51:53 -0000
***************
*** 538,543 ****
--- 538,544 ----
"lc_time",
"log_duration",
"log_executor_stats",
+ "log_min_duration_statement",
"log_min_error_statement",
"log_min_messages",
"log_parser_stats",
Index: src/include/utils/guc.h
===================================================================
RCS file: /cvsroot/pgsql-server/src/include/utils/guc.h,v
retrieving revision 1.31
diff -c -c -r1.31 guc.h
*** src/include/utils/guc.h 6 May 2003 20:26:28 -0000 1.31
--- src/include/utils/guc.h 11 Jun 2003 17:51:54 -0000
***************
*** 142,145 ****
--- 142,147 ----
void read_nondefault_variables(void);
#endif
+ extern int log_min_duration_statement;
+
#endif /* GUC_H */
