Re: Log a sample of transactions

On 2/14/19 9:14 PM, Andres Freund wrote:
> Hi,
> 

Hello Andres,

> On 2019-01-26 11:44:58 +0100, Adrien NAYRAT wrote:
>> +     <varlistentry id="guc-transaction-sample-rate" xreflabel="log_transaction_sample_rate">
>> +      <term><varname>log_transaction_sample_rate</varname> (<type>real</type>)
>> +      <indexterm>
>> +       <primary><varname>log_transaction_sample_rate</varname> configuration parameter</primary>
>> +      </indexterm>
>> +      </term>
>> +       <listitem>
>> +        <para>
>> +         Set the fraction of transactions whose statements are logged. It applies
>> +         to each new transaction regardless of their duration. The default is
>> +         <literal>0</literal>, meaning do not log statements from this transaction.
>> +         Setting this to <literal>1</literal> logs all statements for all transactions.
>> +         Logging can be disabled inside a transaction by setting this to 0.
>> +         <varname>log_transaction_sample_rate</varname> is helpful to track a
>> +         sample of transaction.
>> +        </para>
>> +       </listitem>
>> +      </varlistentry>
>> +
>>        </variablelist>
> 
> I wonder if this doesn't need a warning, explaining that using this when
> there are large transactions could lead to slowdowns.

Yes, I will add some wording

> 
> 
>>       <para>
>> diff --git a/src/backend/access/transam/xact.c b/src/backend/access/transam/xact.c
>> index 7c3a9c1e89..1a52c10c39 100644
>> --- a/src/backend/access/transam/xact.c
>> +++ b/src/backend/access/transam/xact.c
>> @@ -1821,6 +1821,9 @@ StartTransaction(void)
>>       s->state = TRANS_START;
>>       s->transactionId = InvalidTransactionId;    /* until assigned */
>>   
>> +    /* Determine if we log statements in this transaction */
>> +    xact_is_sampled = 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 e773f20d9f..a11667834e 100644
>> --- a/src/backend/tcop/postgres.c
>> +++ b/src/backend/tcop/postgres.c
>> @@ -100,7 +100,8 @@ int            max_stack_depth = 100;
>>   /* wait N seconds to allow attach from a debugger */
>>   int            PostAuthDelay = 0;
>>   
>> -
>> +/* flag for logging statements in a transaction */
>> +bool        xact_is_sampled = false;
> 
> It seems pretty weird to have this in postgres.c, given you declared it
> in xact.h?

Yes, I have to revise my C. I will move it to 
src/backend/access/transam/xact.c

> 
> 
>> @@ -2218,7 +2221,8 @@ 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 && log_xact_sample_rate > 0))
> 
> Why are both of these checked? ISTM once xact_is_sampled is set, we
> ought not to respect a different value of log_xact_sample_rate for the
> rest of that transaction.

I added theses checks to allow to disable logging during a sampled 
transaction, per suggestion of Masahiko Sawada:
https://www.postgresql.org/message-id/CAD21AoD4t%2BhTV6XfK5Yz%3DEocB8oMyJSYFfjAryCDYtqfib2GrA%40mail.gmail.com

> 
> 
> As far as I can tell xact_is_sampled is not properly reset in case of
> errors?
> 

Yes, I wonder where we should reset it? Is it in AbortTransaction() or 
CleanupTransaction()?

Thanks!