database/postgres
1
0
Fork 0
mirror of https://github.com/postgres/postgres.git synced 2025-06-17 17:02:08 +03:00
Code Activity

Allow sampling of statements depending on duration

Browse Source 
This allows logging a sample of statements, without incurring excessive
log traffic (which may impact performance).  This can be useful when
analyzing 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 are
considered for sampling. To enable sampling, both those GUCs have to
be set correctly.

The existing log_min_duration_statement GUC has a higher priority, i.e.
statements with duration exceeding log_min_duration_statement will be
always logged, irrespectedly of how the sampling is configured. This
means only configurations

  log_min_duration_sample < log_min_duration_statement

do actually sample the statements, instead of logging everything.

Author: Adrien Nayrat
Reviewed-by: David Rowley, Vik Fearing, Tomas Vondra
Discussion: https://postgr.es/m/bbe0a1a8-a8f7-3be2-155a-888e661cc06c@anayrat.info
This commit is contained in:
Tomas Vondra
2019-11-04 01:57:45 +01:00
parent 11d9ac28e5
commit 6e3e6cc0e8
5 changed files with 153 additions and 12 deletions
Download Patch File Download Diff File Expand all files Collapse all files

40
src/backend/tcop/postgres.c
View File

@ -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;