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 2166b99fc4eeb23605da6b8e9c20406818b5771d..915296310ce30aed6f5b5dd146b33d806004f370 100644 (file)
--- 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 e9ed92b70bb3eb91d8605709013b6b9a1a942913..b04fdb5d5ed6b6d5e14648223d5169b9605ea95c 100644 (file)
--- 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 f9ce3d8f22a35a69d558e332e84d1e7be27a6377..44a59e1d4fb6fb7ffdc67c24f6e77b0824549bfa 100644 (file)
--- 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 cd5a65be75b58778aa6e53863501170e036a991e..83a9fc2b4c6968ae3955a38ec766874f89e7292d 100644 (file)
--- 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 9b15361403ebdf08cda98e8da9e72e6e5a0e5fc1..f31d419f79552ba36e9093d500cc6406a09313fa 100644 (file)
--- 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 b550343c4db51ef4b0fbdb8658e866b318a10659..d787f929f7f8594d676a778440d916733c3d1e3e 100644 (file)
--- 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 2712a774f7d9cdae8501b4b17faf1cee42b111c0..34cebd540dc2e2b7d501111ef3d90f6bbc67bc6e 100644 (file)
--- 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;