diff options
| -rw-r--r-- | doc/src/sgml/config.sgml | 85 | ||||
| -rw-r--r-- | src/backend/tcop/postgres.c | 40 | ||||
| -rw-r--r-- | src/backend/utils/misc/guc.c | 27 | ||||
| -rw-r--r-- | src/backend/utils/misc/postgresql.conf.sample | 11 | ||||
| -rw-r--r-- | src/include/utils/guc.h | 2 |
5 files changed, 153 insertions, 12 deletions
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 48d7939d2de..46bc31de4c4 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -5951,6 +5951,12 @@ local0.* /var/log/postgresql </para> <para> + This overrides <xref linkend="guc-log-min-duration-sample"/>, + meaning that queries with duration exceeding this setting are not + subject to sampling and are always logged. + </para> + + <para> For clients using extended query protocol, durations of the Parse, Bind, and Execute steps are logged independently. </para> @@ -5972,6 +5978,85 @@ 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> + Allows to sample the logging of the duration of each completed + statement if the statement ran for at least the specified amount of + time. If this value is specified without units, it is taken as milliseconds. + Setting this to zero samples all statement durations. + Minus-one (the default) disables sampling statement durations. + For example, if you set it to <literal>250ms</literal> + then all SQL statements that run 250ms or longer will be considered + for sampling, with sample rate is controlled by <xref linkend="guc-log-statement-sample-rate"/>. + Enabling this parameter can be helpful when the traffic too high to + sample all queries. + Only superusers can change this setting. + </para> + + <para> + This option has lower priority than <xref linkend="guc-log-min-duration-statement"/>, + meaning that statements with durations exceeding <xref linkend="guc-log-min-duration-statement"/> + are not subject to sampling and are always logged. + </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> + <primary><varname>log_statement_sample_rate</varname> configuration parameter</primary> + </indexterm> + </term> + <listitem> + <para> + Determines the fraction of statements with duration exceeding + <xref linkend="guc-log-min-duration-sample"/> to be logged. + This is a statistical parameter, for example <literal>0.5</literal> + means there is statistically one in two chances to log the statement. + The default is <literal>1.0</literal>, meaning log all such + statements. + Setting this to zero disables sampling logging, same as setting + <varname>log_min_duration_sample</varname> to + <literal>-1</literal>. + <varname>log_statement_sample_rate</varname> is helpful when the + traffic is too high to log all queries. + Only superusers can change this setting. + </para> + <note> + <para> + Like all statement-logging options, this option can add significant + overhead. + </para> + </note> + </listitem> + </varlistentry> + <varlistentry id="guc-log-transaction-sample-rate" xreflabel="log_transaction_sample_rate"> <term><varname>log_transaction_sample_rate</varname> (<type>real</type>) <indexterm> diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c index 4bec40aa287..82894eadc66 100644 --- a/src/backend/tcop/postgres.c +++ b/src/backend/tcop/postgres.c @@ -2235,12 +2235,15 @@ 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_sample >= 0 || + log_min_duration_statement >= 0 || xact_is_sampled) { long secs; int usecs; int msecs; - bool exceeded; + bool exceeded_duration; + bool exceeded_sample_duration; + bool in_sample = false; TimestampDifference(GetCurrentStatementStartTimestamp(), GetCurrentTimestamp(), @@ -2248,20 +2251,35 @@ check_log_duration(char *msec_str, bool was_logged) msecs = usecs / 1000; /* - * This odd-looking test for log_min_duration_statement being exceeded - * is designed to avoid integer overflow with very long durations: - * don't compute secs * 1000 until we've verified it will fit in int. + * This odd-looking test for log_min_duration_* being exceeded is + * designed to avoid integer overflow with very long durations: don't + * compute secs * 1000 until we've verified it will fit in int. */ - exceeded = (log_min_duration_statement == 0 || - (log_min_duration_statement > 0 && - (secs > log_min_duration_statement / 1000 || - secs * 1000 + msecs >= log_min_duration_statement))); + exceeded_duration = (log_min_duration_statement == 0 || + (log_min_duration_statement > 0 && + (secs > log_min_duration_statement / 1000 || + secs * 1000 + msecs >= log_min_duration_statement))); - if (exceeded || log_duration || xact_is_sampled) + exceeded_sample_duration = (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 unecessary random() call + * if log_statement_sample_rate = 1. + */ + if (exceeded_sample_duration) + in_sample = log_statement_sample_rate != 0 && + (log_statement_sample_rate == 1 || + random() <= log_statement_sample_rate * MAX_RANDOM_VALUE); + + if (exceeded_duration || in_sample || log_duration || xact_is_sampled) { snprintf(msec_str, 32, "%ld.%03d", secs * 1000 + msecs, usecs % 1000); - if ((exceeded || xact_is_sampled) && !was_logged) + if ((exceeded_duration || in_sample || xact_is_sampled) && !was_logged) return 2; else return 1; diff --git a/src/backend/utils/misc/guc.c b/src/backend/utils/misc/guc.c index 31a5ef04747..e84c8cc4cfc 100644 --- a/src/backend/utils/misc/guc.c +++ b/src/backend/utils/misc/guc.c @@ -509,8 +509,10 @@ bool session_auth_is_superuser; int log_min_error_statement = ERROR; int log_min_messages = WARNING; int client_min_messages = NOTICE; +int log_min_duration_sample = -1; int log_min_duration_statement = -1; int log_temp_files = -1; +double log_statement_sample_rate = 1.0; double log_xact_sample_rate = 0; int trace_recovery_messages = LOG; @@ -2701,9 +2703,22 @@ static struct config_int ConfigureNamesInt[] = }, { + {"log_min_duration_sample", PGC_SUSET, LOGGING_WHEN, + gettext_noop("Sets the minimum execution time above which " + "a sample of statements will be logged." + " Sampling is determined by log_statement_sample_rate."), + gettext_noop("Zero log a sample of all queries. -1 turns this feature off."), + GUC_UNIT_MS + }, + &log_min_duration_sample, + -1, -1, INT_MAX, + NULL, NULL, NULL + }, + + { {"log_min_duration_statement", PGC_SUSET, LOGGING_WHEN, gettext_noop("Sets the minimum execution time above which " - "statements will be logged."), + "all statements will be logged."), gettext_noop("Zero prints all queries. -1 turns this feature off."), GUC_UNIT_MS }, @@ -3431,6 +3446,16 @@ static struct config_real ConfigureNamesReal[] = }, { + {"log_statement_sample_rate", PGC_SUSET, LOGGING_WHEN, + gettext_noop("Fraction of statements exceeding log_min_duration_sample to be logged."), + gettext_noop("Use a value between 0.0 (never log) and 1.0 (always log).") + }, + &log_statement_sample_rate, + 1.0, 0.0, 1.0, + NULL, NULL, NULL + }, + + { {"log_transaction_sample_rate", PGC_SUSET, LOGGING_WHEN, gettext_noop("Set the fraction of transactions to log for new transactions."), gettext_noop("Logs all statements from a fraction of transactions. " diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample index 0fc23e3a612..be02a76d9d8 100644 --- a/src/backend/utils/misc/postgresql.conf.sample +++ b/src/backend/utils/misc/postgresql.conf.sample @@ -493,6 +493,17 @@ # statements running at least this number # of milliseconds +#log_min_duration_sample = -1 # -1 is disabled, 0 logs a sample of statements + # and their durations, > 0 logs only a sample of + # statements running at least this number + # of milliseconds + # Sample fraction is determined by log_statement_sample_rate + +#log_statement_sample_rate = 1.0 # Fraction of logged statements exceeding + # log_min_duration_sample to be logged. + # 1.0 logs all such statements, 0.0 never logs. + + #log_transaction_sample_rate = 0.0 # Fraction of transactions whose statements # are logged regardless of their duration. 1.0 logs all # statements from all transactions, 0.0 never logs. diff --git a/src/include/utils/guc.h b/src/include/utils/guc.h index 6791e0cbc20..9aa3d025965 100644 --- a/src/include/utils/guc.h +++ b/src/include/utils/guc.h @@ -251,8 +251,10 @@ extern bool session_auth_is_superuser; extern int log_min_error_statement; extern PGDLLIMPORT int log_min_messages; extern PGDLLIMPORT int client_min_messages; +extern int log_min_duration_sample; extern int log_min_duration_statement; extern int log_temp_files; +extern double log_statement_sample_rate; extern double log_xact_sample_rate; extern int temp_file_limit; |