From: Alvaro Herrera Date: Wed, 3 Apr 2019 21:43:59 +0000 (-0300) Subject: Log all statements from a sample of transactions X-Git-Tag: REL_12_BETA1~321 X-Git-Url: https://granicus.if.org/sourcecode?a=commitdiff_plain;h=799e220346f1387e823a4dbdc3b1c8c3cdc5c3e0;p=postgresql Log all statements from a sample of transactions This is useful to obtain a view of the different transaction types in an application, regardless of the durations of the statements each runs. Author: Adrien Nayrat Reviewed-by: Masahiko Sawada, Hayato Kuroda, Andres Freund --- diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 2166b99fc4..915296310c 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -5871,6 +5871,32 @@ local0.* /var/log/postgresql + + log_transaction_sample_rate (real) + + log_transaction_sample_rate configuration parameter + + + + + Set the fraction of transactions whose statements are all logged, + in addition to statements logged for other reasons. It applies to + each new transaction regardless of its statements' durations. + The default is 0, meaning not to log statements + from any additional transaction. Setting this to 1 + logs all statements for all transactions. + log_transaction_sample_rate is helpful to track a + sample of transaction. + + + + Like all statement-logging options, this option can add significant + overhead. + + + + + diff --git a/src/backend/access/transam/xact.c b/src/backend/access/transam/xact.c index e9ed92b70b..b04fdb5d5e 100644 --- a/src/backend/access/transam/xact.c +++ b/src/backend/access/transam/xact.c @@ -264,6 +264,9 @@ static char *prepareGID; */ static bool forceSyncCommit = false; +/* Flag for logging statements in a transaction. */ +bool xact_is_sampled = false; + /* * Private context for transaction-abort work --- we reserve space for this * at startup to ensure that AbortTransaction and AbortSubTransaction can work @@ -1903,6 +1906,11 @@ StartTransaction(void) s->state = TRANS_START; s->fullTransactionId = InvalidFullTransactionId; /* until assigned */ + /* Determine if statements are logged in this transaction */ + xact_is_sampled = log_xact_sample_rate != 0 && + (log_xact_sample_rate == 1 || + random() <= log_xact_sample_rate * MAX_RANDOM_VALUE); + /* * initialize current transaction state fields * diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c index f9ce3d8f22..44a59e1d4f 100644 --- a/src/backend/tcop/postgres.c +++ b/src/backend/tcop/postgres.c @@ -2194,6 +2194,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. + * We also check if this statement in this transaction must be logged + * (regardless of its duration). * * Returns: * 0 if no logging is needed @@ -2209,7 +2211,7 @@ check_log_statement(List *stmt_list) int check_log_duration(char *msec_str, bool was_logged) { - if (log_duration || log_min_duration_statement >= 0) + if (log_duration || log_min_duration_statement >= 0 || xact_is_sampled) { long secs; int usecs; @@ -2243,11 +2245,11 @@ check_log_duration(char *msec_str, bool was_logged) (log_statement_sample_rate == 1 || random() <= log_statement_sample_rate * MAX_RANDOM_VALUE); - if ((exceeded && in_sample) || log_duration) + if ((exceeded && in_sample) || log_duration || xact_is_sampled) { snprintf(msec_str, 32, "%ld.%03d", secs * 1000 + msecs, usecs % 1000); - if (exceeded && !was_logged) + if ((exceeded || 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 cd5a65be75..83a9fc2b4c 100644 --- a/src/backend/utils/misc/guc.c +++ b/src/backend/utils/misc/guc.c @@ -510,6 +510,7 @@ int client_min_messages = NOTICE; 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; int temp_file_limit = -1; @@ -3386,6 +3387,18 @@ static struct config_real ConfigureNamesReal[] = 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. " + "Use a value between 0.0 (never log) and 1.0 (log all " + "statements for all transactions).") + }, + &log_xact_sample_rate, + 0.0, 0.0, 1.0, + NULL, NULL, NULL + }, + /* End-of-list marker */ { {NULL, 0, 0, NULL, NULL}, NULL, 0.0, 0.0, 0.0, NULL, NULL, NULL diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample index 9b15361403..f31d419f79 100644 --- a/src/backend/utils/misc/postgresql.conf.sample +++ b/src/backend/utils/misc/postgresql.conf.sample @@ -495,6 +495,10 @@ # log_min_duration_statement. 1.0 logs all statements, # 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. + # - What to Log - #debug_print_parse = off diff --git a/src/include/access/xact.h b/src/include/access/xact.h index b550343c4d..d787f929f7 100644 --- a/src/include/access/xact.h +++ b/src/include/access/xact.h @@ -55,6 +55,9 @@ extern PGDLLIMPORT int XactIsoLevel; extern bool DefaultXactReadOnly; extern bool XactReadOnly; +/* flag for logging statements in this transaction */ +extern bool xact_is_sampled; + /* * Xact is deferrable -- only meaningful (currently) for read only * SERIALIZABLE transactions diff --git a/src/include/utils/guc.h b/src/include/utils/guc.h index 2712a774f7..34cebd540d 100644 --- a/src/include/utils/guc.h +++ b/src/include/utils/guc.h @@ -252,6 +252,7 @@ extern PGDLLIMPORT int client_min_messages; 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;