log-sample-rework.patch
text/plain
Filename: log-sample-rework.patch
Type: text/plain
Part: 0
Patch
Same data as JSON:
GET /api/v1/attachments/:id/patch
the parsed metadata as JSON — format, series position, per-file stats; never the diff bytes.
API reference →
Format: unified
| File | + | − |
|---|---|---|
| doc/src/sgml/config.sgml | 43 | 2 |
| src/backend/tcop/postgres.c | 15 | 4 |
| src/backend/utils/misc/guc.c | 15 | 2 |
| src/backend/utils/misc/postgresql.conf.sample | 7 | 3 |
| src/include/utils/guc.h | 1 | 0 |
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index c91e3e1550..8cb695044b 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -5850,8 +5850,7 @@ local0.* /var/log/postgresql
<para>
Causes the duration of each completed statement to be logged
if the statement ran for at least the specified number of
- milliseconds, modulated by <varname>log_statement_sample_rate</varname>.
- Setting this to zero prints all statement durations.
+ milliseconds. Setting this to zero prints all statement durations.
<literal>-1</literal> (the default) disables logging statements due to
exceeding duration threshold; for example, if you set it to
<literal>250ms</literal>, then all SQL statements that run 250ms or
@@ -5882,6 +5881,48 @@ local0.* /var/log/postgresql
</listitem>
</varlistentry>
+ <varlistentry id="guc-log-min-duration-sample" xreflabel="log_min_duration_sample">
+ <term><varname>log_min_duration_sample</varname> (<type>integer</type>)
+ <indexterm>
+ <primary><varname>log_min_duration_sample</varname> configuration parameter</primary>
+ </indexterm>
+ </term>
+ <listitem>
+ <para>
+ Causes the duration of each completed statement to be logged
+ if the statement ran for at least the specified number of
+ milliseconds, modulated by <varname>log_statement_sample_rate</varname>.
+ Setting this to zero samples all statement durations.
+ <literal>-1</literal> (the default) disables sampling of statements;
+ for example, if you set it to <literal>250ms</literal>, then all
+ SQL statements that run 250ms or longer will be sampled for
+ logging. Statements with duration exceeding
+ <varname>log_min_duration_statement</varname> are not subject to
+ sampling and are logged every time.
+ </para>
+
+ <para>
+ For clients using extended query protocol, durations of the Parse,
+ Bind, and Execute steps are logged independently.
+ </para>
+
+ <note>
+ <para>
+ When using this option together with
+ <xref linkend="guc-log-statement"/>,
+ the text of statements that are logged because of
+ <varname>log_statement</varname> will not be repeated in the
+ duration log message.
+ If you are not using <application>syslog</application>, it is recommended
+ that you log the PID or session ID using
+ <xref linkend="guc-log-line-prefix"/>
+ so that you can link the statement message to the later
+ duration message using the process ID or session ID.
+ </para>
+ </note>
+ </listitem>
+ </varlistentry>
+
<varlistentry id="guc-log-statement-sample-rate" xreflabel="log_statement_sample_rate">
<term><varname>log_statement_sample_rate</varname> (<type>real</type>)
<indexterm>
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index a6505c7335..ae1def0f37 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -2213,7 +2213,8 @@ check_log_statement(List *stmt_list)
/*
* check_log_duration
* Determine whether current command's duration should be logged.
- * If log_statement_sample_rate < 1.0, log only a sample.
+ * If log_statement_sample_rate < 1.0, log only a sample of queries
+ * between log_min_duration_sample and log_min_duration_statement.
* We also check if this statement in this transaction must be logged
* (regardless of its duration).
*
@@ -2231,12 +2232,14 @@ check_log_statement(List *stmt_list)
int
check_log_duration(char *msec_str, bool was_logged)
{
- if (log_duration || log_min_duration_statement >= 0 || xact_is_sampled)
+ if (log_duration || log_min_duration_statement >= 0 ||
+ log_min_duration_sample || xact_is_sampled)
{
long secs;
int usecs;
int msecs;
bool exceeded;
+ bool exceeded_sample;
bool in_sample;
TimestampDifference(GetCurrentStatementStartTimestamp(),
@@ -2254,18 +2257,26 @@ check_log_duration(char *msec_str, bool was_logged)
(secs > log_min_duration_statement / 1000 ||
secs * 1000 + msecs >= log_min_duration_statement)));
+ /*
+ * Use the same odd-looking test for log_min_duration_sample.
+ */
+ exceeded_sample = (log_min_duration_sample == 0 ||
+ (log_min_duration_sample > 0 &&
+ (secs > log_min_duration_sample / 1000 ||
+ secs * 1000 + msecs >= log_min_duration_sample)));
+
/*
* Do not log if log_statement_sample_rate = 0. Log a sample if
* log_statement_sample_rate <= 1 and avoid unnecessary random() call
* if log_statement_sample_rate = 1. But don't compute any of this
* unless needed.
*/
- in_sample = exceeded &&
+ in_sample = exceeded_sample &&
log_statement_sample_rate != 0 &&
(log_statement_sample_rate == 1 ||
random() <= log_statement_sample_rate * MAX_RANDOM_VALUE);
- if ((exceeded && in_sample) || log_duration || xact_is_sampled)
+ if ((exceeded || in_sample) || log_duration || xact_is_sampled)
{
snprintf(msec_str, 32, "%ld.%03d",
secs * 1000 + msecs, usecs % 1000);
diff --git a/src/backend/utils/misc/guc.c b/src/backend/utils/misc/guc.c
index fc463601ff..b3d687b1a7 100644
--- a/src/backend/utils/misc/guc.c
+++ b/src/backend/utils/misc/guc.c
@@ -510,6 +510,7 @@ int log_min_error_statement = ERROR;
int log_min_messages = WARNING;
int client_min_messages = NOTICE;
int log_min_duration_statement = -1;
+int log_min_duration_sample = -1;
int log_temp_files = -1;
double log_statement_sample_rate = 1.0;
double log_xact_sample_rate = 0;
@@ -2705,8 +2706,7 @@ static struct config_int ConfigureNamesInt[] =
{"log_min_duration_statement", PGC_SUSET, LOGGING_WHEN,
gettext_noop("Sets the minimum execution time above which "
"statements will be logged."),
- gettext_noop("Zero prints all queries, subject to log_statement_sample_rate. "
- "-1 turns this feature off."),
+ gettext_noop("Zero prints all queries, -1 turns this feature off."),
GUC_UNIT_MS
},
&log_min_duration_statement,
@@ -2714,6 +2714,19 @@ static struct config_int ConfigureNamesInt[] =
NULL, NULL, NULL
},
+ {
+ {"log_min_duration_sample", PGC_SUSET, LOGGING_WHEN,
+ gettext_noop("Sets the minimum execution time above which "
+ "statements will be sampled for logging."),
+ gettext_noop("Zero samples all queries, subject to log_statement_sample_rate. "
+ "-1 turns this feature off."),
+ GUC_UNIT_MS
+ },
+ &log_min_duration_sample,
+ -1, -1, INT_MAX,
+ NULL, NULL, NULL
+ },
+
{
{"log_autovacuum_min_duration", PGC_SIGHUP, LOGGING_WHAT,
gettext_noop("Sets the minimum execution time above which "
diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample
index cfad86c02a..2fa2871137 100644
--- a/src/backend/utils/misc/postgresql.conf.sample
+++ b/src/backend/utils/misc/postgresql.conf.sample
@@ -488,10 +488,14 @@
# fatal
# panic (effectively off)
-#log_min_duration_statement = -1 # logs statements and their durations
+#log_min_duration_statement = -1 # logs statements and their durations.
+ # -1 is disabled, 0 logs all statements, > 0 logs only
+ # statements running at least this number of milliseconds.
+
+#log_min_duration_sample = -1 # logs statements and their durations
# according to log_statement_sample_rate. -1 is disabled,
- # 0 logs all statements, > 0 logs only statements running
- # at least this number of milliseconds.
+ # 0 samples all statements, > 0 samples only statements
+ # running at least this number of milliseconds.
#log_statement_sample_rate = 1.0 # Fraction of logged statements exceeding
# log_min_duration_statement to be logged.
diff --git a/src/include/utils/guc.h b/src/include/utils/guc.h
index e709177c37..544a33fcd5 100644
--- a/src/include/utils/guc.h
+++ b/src/include/utils/guc.h
@@ -252,6 +252,7 @@ extern int log_min_error_statement;
extern PGDLLIMPORT int log_min_messages;
extern PGDLLIMPORT int client_min_messages;
extern int log_min_duration_statement;
+extern int log_min_duration_sample;
extern int log_temp_files;
extern double log_statement_sample_rate;
extern double log_xact_sample_rate;