Movatterモバイル変換

[0]ホーム
URL:

Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

 Sign up
Appearance settings

Commit6e3e6cc

Browse files
committed
Allow sampling of statements depending on duration
This allows logging a sample of statements, without incurring excessivelog traffic (which may impact performance). This can be useful whenanalyzing workloads with lots of short queries.The sampling is configured using two new GUC parameters: * log_min_duration_sample - minimum required statement duration * log_statement_sample_rate - sample rate (0.0 - 1.0)Only statements with duration exceeding log_min_duration_sample areconsidered for sampling. To enable sampling, both those GUCs have tobe set correctly.The existing log_min_duration_statement GUC has a higher priority, i.e.statements with duration exceeding log_min_duration_statement will bealways logged, irrespectedly of how the sampling is configured. Thismeans only configurations log_min_duration_sample < log_min_duration_statementdo actually sample the statements, instead of logging everything.Author: Adrien NayratReviewed-by: David Rowley, Vik Fearing, Tomas VondraDiscussion:https://postgr.es/m/bbe0a1a8-a8f7-3be2-155a-888e661cc06c@anayrat.info
1 parent11d9ac2 commit6e3e6cc

File tree

5 files changed

+153
-12
lines changed

5 files changed

+153
-12
lines changed

‎doc/src/sgml/config.sgml

Lines changed: 85 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -5950,6 +5950,12 @@ local0.* /var/log/postgresql
59505950
Only superusers can change this setting.
59515951
</para>
59525952

5953+
<para>
5954+
This overrides <xref linkend="guc-log-min-duration-sample"/>,
5955+
meaning that queries with duration exceeding this setting are not
5956+
subject to sampling and are always logged.
5957+
</para>
5958+
59535959
<para>
59545960
For clients using extended query protocol, durations of the Parse,
59555961
Bind, and Execute steps are logged independently.
@@ -5972,6 +5978,85 @@ local0.* /var/log/postgresql
59725978
</listitem>
59735979
</varlistentry>
59745980

5981+
<varlistentry id="guc-log-min-duration-sample" xreflabel="log_min_duration_sample">
5982+
<term><varname>log_min_duration_sample</varname> (<type>integer</type>)
5983+
<indexterm>
5984+
<primary><varname>log_min_duration_sample</varname> configuration parameter</primary>
5985+
</indexterm>
5986+
</term>
5987+
<listitem>
5988+
<para>
5989+
Allows to sample the logging of the duration of each completed
5990+
statement if the statement ran for at least the specified amount of
5991+
time. If this value is specified without units, it is taken as milliseconds.
5992+
Setting this to zero samples all statement durations.
5993+
Minus-one (the default) disables sampling statement durations.
5994+
For example, if you set it to <literal>250ms</literal>
5995+
then all SQL statements that run 250ms or longer will be considered
5996+
for sampling, with sample rate is controlled by <xref linkend="guc-log-statement-sample-rate"/>.
5997+
Enabling this parameter can be helpful when the traffic too high to
5998+
sample all queries.
5999+
Only superusers can change this setting.
6000+
</para>
6001+
6002+
<para>
6003+
This option has lower priority than <xref linkend="guc-log-min-duration-statement"/>,
6004+
meaning that statements with durations exceeding <xref linkend="guc-log-min-duration-statement"/>
6005+
are not subject to sampling and are always logged.
6006+
</para>
6007+
6008+
<para>
6009+
For clients using extended query protocol, durations of the Parse,
6010+
Bind, and Execute steps are logged independently.
6011+
</para>
6012+
6013+
<note>
6014+
<para>
6015+
When using this option together with
6016+
<xref linkend="guc-log-statement"/>,
6017+
the text of statements that are logged because of
6018+
<varname>log_statement</varname> will not be repeated in the
6019+
duration log message.
6020+
If you are not using <application>syslog</application>, it is recommended
6021+
that you log the PID or session ID using
6022+
<xref linkend="guc-log-line-prefix"/>
6023+
so that you can link the statement message to the later
6024+
duration message using the process ID or session ID.
6025+
</para>
6026+
</note>
6027+
</listitem>
6028+
</varlistentry>
6029+
6030+
<varlistentry id="guc-log-statement-sample-rate" xreflabel="log_statement_sample_rate">
6031+
<term><varname>log_statement_sample_rate</varname> (<type>real</type>)
6032+
<indexterm>
6033+
<primary><varname>log_statement_sample_rate</varname> configuration parameter</primary>
6034+
</indexterm>
6035+
</term>
6036+
<listitem>
6037+
<para>
6038+
Determines the fraction of statements with duration exceeding
6039+
<xref linkend="guc-log-min-duration-sample"/> to be logged.
6040+
This is a statistical parameter, for example <literal>0.5</literal>
6041+
means there is statistically one in two chances to log the statement.
6042+
The default is <literal>1.0</literal>, meaning log all such
6043+
statements.
6044+
Setting this to zero disables sampling logging, same as setting
6045+
<varname>log_min_duration_sample</varname> to
6046+
<literal>-1</literal>.
6047+
<varname>log_statement_sample_rate</varname> is helpful when the
6048+
traffic is too high to log all queries.
6049+
Only superusers can change this setting.
6050+
</para>
6051+
<note>
6052+
<para>
6053+
Like all statement-logging options, this option can add significant
6054+
overhead.
6055+
</para>
6056+
</note>
6057+
</listitem>
6058+
</varlistentry>
6059+
59756060
<varlistentry id="guc-log-transaction-sample-rate" xreflabel="log_transaction_sample_rate">
59766061
<term><varname>log_transaction_sample_rate</varname> (<type>real</type>)
59776062
<indexterm>

‎src/backend/tcop/postgres.c

Lines changed: 29 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -2235,33 +2235,51 @@ check_log_statement(List *stmt_list)
22352235
int
22362236
check_log_duration(char*msec_str,boolwas_logged)
22372237
{
2238-
if (log_duration||log_min_duration_statement >=0||xact_is_sampled)
2238+
if (log_duration||log_min_duration_sample >=0||
2239+
log_min_duration_statement >=0||xact_is_sampled)
22392240
{
22402241
longsecs;
22412242
intusecs;
22422243
intmsecs;
2243-
boolexceeded;
2244+
boolexceeded_duration;
2245+
boolexceeded_sample_duration;
2246+
boolin_sample= false;
22442247

22452248
TimestampDifference(GetCurrentStatementStartTimestamp(),
22462249
GetCurrentTimestamp(),
22472250
&secs,&usecs);
22482251
msecs=usecs /1000;
22492252

22502253
/*
2251-
* This odd-looking test forlog_min_duration_statement being exceeded
2252-
*isdesigned to avoid integer overflow with very long durations:
2253-
*don'tcompute secs * 1000 until we've verified it will fit in int.
2254+
* This odd-looking test forlog_min_duration_* being exceeded is
2255+
* designed to avoid integer overflow with very long durations: don't
2256+
* compute secs * 1000 until we've verified it will fit in int.
22542257
*/
2255-
exceeded= (log_min_duration_statement==0||
2256-
(log_min_duration_statement>0&&
2257-
(secs>log_min_duration_statement /1000||
2258-
secs*1000+msecs >=log_min_duration_statement)));
2258+
exceeded_duration= (log_min_duration_statement==0||
2259+
(log_min_duration_statement>0&&
2260+
(secs>log_min_duration_statement /1000||
2261+
secs*1000+msecs >=log_min_duration_statement)));
22592262

2260-
if (exceeded||log_duration||xact_is_sampled)
2263+
exceeded_sample_duration= (log_min_duration_sample==0||
2264+
(log_min_duration_sample>0&&
2265+
(secs>log_min_duration_sample /1000||
2266+
secs*1000+msecs >=log_min_duration_sample)));
2267+
2268+
/*
2269+
* Do not log if log_statement_sample_rate = 0. Log a sample if
2270+
* log_statement_sample_rate <= 1 and avoid unecessary random() call
2271+
* if log_statement_sample_rate = 1.
2272+
*/
2273+
if (exceeded_sample_duration)
2274+
in_sample=log_statement_sample_rate!=0&&
2275+
(log_statement_sample_rate==1||
2276+
random() <=log_statement_sample_rate*MAX_RANDOM_VALUE);
2277+
2278+
if (exceeded_duration||in_sample||log_duration||xact_is_sampled)
22612279
{
22622280
snprintf(msec_str,32,"%ld.%03d",
22632281
secs*1000+msecs,usecs %1000);
2264-
if ((exceeded||xact_is_sampled)&& !was_logged)
2282+
if ((exceeded_duration||in_sample||xact_is_sampled)&& !was_logged)
22652283
return2;
22662284
else
22672285
return1;

‎src/backend/utils/misc/guc.c

Lines changed: 26 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -509,8 +509,10 @@ boolsession_auth_is_superuser;
509509
intlog_min_error_statement=ERROR;
510510
intlog_min_messages=WARNING;
511511
intclient_min_messages=NOTICE;
512+
intlog_min_duration_sample=-1;
512513
intlog_min_duration_statement=-1;
513514
intlog_temp_files=-1;
515+
doublelog_statement_sample_rate=1.0;
514516
doublelog_xact_sample_rate=0;
515517
inttrace_recovery_messages=LOG;
516518

@@ -2700,10 +2702,23 @@ static struct config_int ConfigureNamesInt[] =
27002702
NULL,NULL,NULL
27012703
},
27022704

2705+
{
2706+
{"log_min_duration_sample",PGC_SUSET,LOGGING_WHEN,
2707+
gettext_noop("Sets the minimum execution time above which "
2708+
"a sample of statements will be logged."
2709+
" Sampling is determined by log_statement_sample_rate."),
2710+
gettext_noop("Zero log a sample of all queries. -1 turns this feature off."),
2711+
GUC_UNIT_MS
2712+
},
2713+
&log_min_duration_sample,
2714+
-1,-1,INT_MAX,
2715+
NULL,NULL,NULL
2716+
},
2717+
27032718
{
27042719
{"log_min_duration_statement",PGC_SUSET,LOGGING_WHEN,
27052720
gettext_noop("Sets the minimum execution time above which "
2706-
"statements will be logged."),
2721+
"allstatements will be logged."),
27072722
gettext_noop("Zero prints all queries. -1 turns this feature off."),
27082723
GUC_UNIT_MS
27092724
},
@@ -3430,6 +3445,16 @@ static struct config_real ConfigureNamesReal[] =
34303445
NULL,NULL,NULL
34313446
},
34323447

3448+
{
3449+
{"log_statement_sample_rate",PGC_SUSET,LOGGING_WHEN,
3450+
gettext_noop("Fraction of statements exceeding log_min_duration_sample to be logged."),
3451+
gettext_noop("Use a value between 0.0 (never log) and 1.0 (always log).")
3452+
},
3453+
&log_statement_sample_rate,
3454+
1.0,0.0,1.0,
3455+
NULL,NULL,NULL
3456+
},
3457+
34333458
{
34343459
{"log_transaction_sample_rate",PGC_SUSET,LOGGING_WHEN,
34353460
gettext_noop("Set the fraction of transactions to log for new transactions."),

‎src/backend/utils/misc/postgresql.conf.sample

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -493,6 +493,17 @@
493493
# statements running at least this number
494494
# of milliseconds
495495

496+
#log_min_duration_sample = -1# -1 is disabled, 0 logs a sample of statements
497+
# and their durations, > 0 logs only a sample of
498+
# statements running at least this number
499+
# of milliseconds
500+
# Sample fraction is determined by log_statement_sample_rate
501+
502+
#log_statement_sample_rate = 1.0 # Fraction of logged statements exceeding
503+
# log_min_duration_sample to be logged.
504+
# 1.0 logs all such statements, 0.0 never logs.
505+
506+
496507
#log_transaction_sample_rate = 0.0# Fraction of transactions whose statements
497508
# are logged regardless of their duration. 1.0 logs all
498509
# statements from all transactions, 0.0 never logs.

‎src/include/utils/guc.h

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -251,8 +251,10 @@ extern bool session_auth_is_superuser;
251251
externintlog_min_error_statement;
252252
externPGDLLIMPORTintlog_min_messages;
253253
externPGDLLIMPORTintclient_min_messages;
254+
externintlog_min_duration_sample;
254255
externintlog_min_duration_statement;
255256
externintlog_temp_files;
257+
externdoublelog_statement_sample_rate;
256258
externdoublelog_xact_sample_rate;
257259

258260
externinttemp_file_limit;

0 commit comments

Comments
 (0)
[8]ページ先頭
©2009-2025 Movatter.jp