Tom Lane wrote:
> Bruce Momjian <[EMAIL PROTECTED]> writes:
> > I have not heard from you why we should make it harder (split across two
> > lines), except for consistency with log_statement and log_duration
> > outputs.
>
> That is exactly my argument. I'll freely admit that it's not a strong
> point, but I find the claim that the inconsistent formats will be easier
> to parse to be a much weaker argument, in the absence of any attempt to
> make them *actually* easier to parse (like really truly one line).
>
> [ later ]
> > Should we instead convert newlines to "\n" and output the query as a
> > single line?
>
> That would shore up your position considerably. It needs a little
> thought as to whether this would induce any confusion, and whether we
> really care if so.
OK, patch attached. It does the single-line log_min_duration_statement,
and adds a zero value to always print the duration and statement. I
have also added code to convert end-of-line characters to \n and \r, and
doubles backslashes. It also makes log_statement print as one line, and
shows pg_stat_activity as one line. Without this fix, you get:
test=> select * from pg_stat_activity;
datid | datname | procpid | usesysid | usename | current_query
| query_start
-------+---------+---------+----------+----------+-----------------------------------+-------------------------------
17139 | test | 19167 | 1 | postgres |
|
17139 | test | 19131 | 1 | postgres | select *
from pg_class, pg_proc; | 2003-10-05 15:14:05.338268-04
New output is:
test=> select * from pg_stat_activity;
datid | datname | procpid | usesysid | usename | current_query
| query_start
-------+---------+---------+----------+----------+-----------------------------------+-------------------------------
17139 | test | 20391 | 1 | postgres |
|
17139 | test | 20344 | 1 | postgres | select *\nfrom pg_proc,
pg_class; | 2003-10-05 16:25:07.610427-04
(2 rows)
--
Bruce Momjian | http://candle.pha.pa.us
[EMAIL PROTECTED] | (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.210
diff -c -c -r1.210 runtime.sgml
*** doc/src/sgml/runtime.sgml 3 Oct 2003 19:26:49 -0000 1.210
--- doc/src/sgml/runtime.sgml 5 Oct 2003 20:26:09 -0000
***************
*** 1691,1702 ****
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 their actual duration. Setting this to zero (the default)
! disables time-based logging. For example, if you set it
to <literal>250</literal> then all SQL statements that run longer
! than 250ms will be logged. Enabling this
! option can be useful in tracking down unoptimized queries in
! your applications.
Only superusers can increase this or set it to zero if this option
is set to non-zero by the administrator.
</para>
--- 1691,1702 ----
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 their actual duration. Setting this to zero will print
! all queries with their durations. Minus-one (the default)
! disables time-based logging. For example, if you set it
to <literal>250</literal> then all SQL statements that run longer
! than 250ms will be logged. Enabling this option can be useful
! in tracking down unoptimized queries in your applications.
Only superusers can increase this or set it to zero if this option
is set to non-zero by the administrator.
</para>
Index: src/backend/tcop/postgres.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/tcop/postgres.c,v
retrieving revision 1.370
diff -c -c -r1.370 postgres.c
*** src/backend/tcop/postgres.c 4 Oct 2003 02:47:04 -0000 1.370
--- src/backend/tcop/postgres.c 5 Oct 2003 20:26:12 -0000
***************
*** 150,156 ****
static void finish_xact_command(void);
static void SigHupHandler(SIGNAL_ARGS);
static void FloatExceptionHandler(SIGNAL_ARGS);
!
/* ----------------------------------------------------------------
* routines to obtain user input
--- 150,156 ----
static void finish_xact_command(void);
static void SigHupHandler(SIGNAL_ARGS);
static void FloatExceptionHandler(SIGNAL_ARGS);
! static char *str_add_symbolic_eol(const char *str);
/* ----------------------------------------------------------------
* routines to obtain user input
***************
*** 461,467 ****
if (log_statement)
ereport(LOG,
! (errmsg("query: %s", query_string)));
if (log_parser_stats)
ResetUsage();
--- 461,467 ----
if (log_statement)
ereport(LOG,
! (errmsg("query: %s",
str_add_symbolic_eol(query_string))));
if (log_parser_stats)
ResetUsage();
***************
*** 686,692 ****
*/
debug_query_string = query_string;
! pgstat_report_activity(query_string);
/*
* We use save_log_* so "SET log_duration = true" and "SET
--- 686,692 ----
*/
debug_query_string = query_string;
! pgstat_report_activity(str_add_symbolic_eol(query_string));
/*
* We use save_log_* so "SET log_duration = true" and "SET
***************
*** 694,700 ****
* 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)
--- 694,700 ----
* because gettimeofday() wasn't called. Similarly,
* log_statement_stats has to be captured once.
*/
! if (save_log_duration || save_log_min_duration_statement != -1)
gettimeofday(&start_t, NULL);
if (save_log_statement_stats)
***************
*** 940,946 ****
* 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;
bool print_statement;
--- 940,946 ----
* Combine processing here as we need to calculate the query duration
* in both instances.
*/
! if (save_log_duration || save_log_min_duration_statement != -1)
{
long usecs;
bool print_statement;
***************
*** 957,972 ****
* Output a duration_statement to the log if the query has exceeded
* the min duration, or if we are to print all durations.
*/
! print_statement = (save_log_min_duration_statement > 0 &&
! usecs >=
save_log_min_duration_statement * 1000);
if (save_log_duration || print_statement)
ereport(LOG,
! (errmsg("duration(secs): %ld.%06ld%s%s",
! (long) (stop_t.tv_sec -
start_t.tv_sec),
! (long) (stop_t.tv_usec -
start_t.tv_usec),
! print_statement ? " " : "",
! print_statement ? query_string
: "")));
}
if (save_log_statement_stats)
--- 957,974 ----
* Output a duration_statement to the log if the query has exceeded
* the min duration, or if we are to print all durations.
*/
! print_statement = (save_log_min_duration_statement == 0 ||
! (save_log_min_duration_statement >
0 &&
! usecs >=
save_log_min_duration_statement * 1000));
if (save_log_duration || print_statement)
ereport(LOG,
! (errmsg("duration: %ld.%03ld ms%s%s",
! (long) ((stop_t.tv_sec -
start_t.tv_sec) * 1000 +
! (stop_t.tv_usec -
start_t.tv_usec) / 1000),
! (long) (stop_t.tv_usec -
start_t.tv_usec) % 1000,
! print_statement ? "; " : "",
! print_statement ?
str_add_symbolic_eol(query_string) : "")));
}
if (save_log_statement_stats)
***************
*** 1000,1006 ****
*/
debug_query_string = query_string;
! pgstat_report_activity(query_string);
set_ps_display("PARSE");
--- 1002,1008 ----
*/
debug_query_string = query_string;
! pgstat_report_activity(str_add_symbolic_eol(query_string));
set_ps_display("PARSE");
***************
*** 3196,3198 ****
--- 3198,3236 ----
pfree(str.data);
}
+
+ /*
+ * str_add_symbolic_eol
+ *
+ * This string coverts literal newlines to "\n" for log output.
+ */
+ static char *str_add_symbolic_eol(const char *str)
+ {
+ char *outstr = palloc(strlen(str) * 2 + 1);
+ int len = strlen(str);
+ int i, outlen = 0;
+
+ for (i = 0; i < len; i++)
+ {
+ if (str[i] == '\n')
+ {
+ outstr[outlen++] = '\\';
+ outstr[outlen++] = 'n';
+ }
+ else if (str[i] == '\r')
+ {
+ outstr[outlen++] = '\\';
+ outstr[outlen++] = 'r';
+ }
+ else if (str[i] == '\\')
+ {
+ outstr[outlen++] = '\\';
+ outstr[outlen++] = '\\';
+ }
+ else
+ outstr[outlen++] = str[i];
+ }
+ outstr[outlen++] = '\0';
+ return outstr;
+ }
+
Index: src/backend/utils/misc/guc.c
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/utils/misc/guc.c,v
retrieving revision 1.162
diff -c -c -r1.162 guc.c
*** src/backend/utils/misc/guc.c 3 Oct 2003 19:26:49 -0000 1.162
--- src/backend/utils/misc/guc.c 5 Oct 2003 20:26:19 -0000
***************
*** 128,134 ****
int log_min_messages = NOTICE;
int client_min_messages = NOTICE;
! int log_min_duration_statement = 0;
/*
--- 128,134 ----
int log_min_messages = NOTICE;
int client_min_messages = NOTICE;
! int log_min_duration_statement = -1;
/*
***************
*** 1185,1194 ****
{"log_min_duration_statement", PGC_USERLIMIT, LOGGING_WHEN,
gettext_noop("minimum execution time in milliseconds above
which statements will "
"be logged"),
! gettext_noop("The default is 0 (turning this feature off).")
},
&log_min_duration_statement,
! 0, 0, INT_MAX / 1000, NULL, NULL
},
/* End-of-list marker */
--- 1185,1194 ----
{"log_min_duration_statement", PGC_USERLIMIT, LOGGING_WHEN,
gettext_noop("minimum execution time in milliseconds above
which statements will "
"be logged"),
! gettext_noop("Zero prints all queries. The default is -1
(turning this feature off).")
},
&log_min_duration_statement,
! -1, -1, INT_MAX / 1000, NULL, NULL
},
/* End-of-list marker */
Index: src/backend/utils/misc/postgresql.conf.sample
===================================================================
RCS file: /cvsroot/pgsql-server/src/backend/utils/misc/postgresql.conf.sample,v
retrieving revision 1.91
diff -c -c -r1.91 postgresql.conf.sample
*** src/backend/utils/misc/postgresql.conf.sample 3 Oct 2003 19:26:49 -0000
1.91
--- src/backend/utils/misc/postgresql.conf.sample 5 Oct 2003 20:26:20 -0000
***************
*** 157,165 ****
# 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.
#silent_mode = false # DO NOT USE without Syslog!
--- 157,166 ----
# debug5, debug4, debug3, debug2, debug1,
# info, notice, warning, error, panic(off)
! #log_min_duration_statement = -1 # Log all statements whose
# execution time exceeds the value, in
! # milliseconds. Zero prints all queries.
! # Minus-one disables.
#silent_mode = false # DO NOT USE without Syslog!
---------------------------(end of broadcast)---------------------------
TIP 6: Have you searched our list archives?
http://archives.postgresql.org
