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 21:17:30 -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 250 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. --- 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 250 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. 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 21:17:33 -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_make_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_make_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_make_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 ? " query: " : "", ! print_statement ? str_make_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_make_symbolic_eol(query_string)); set_ps_display("PARSE"); *************** *** 3196,3198 **** --- 3198,3236 ---- pfree(str.data); } + + /* + * str_make_symbolic_eol + * + * This string coverts literal newlines to "\n" for log output. + */ + static char *str_make_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 21:17:37 -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 21:17:37 -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!