Re: Log a sample of transactions - Mailing list pgsql-hackers

On 3/27/19 10:22 AM, Adrien NAYRAT wrote:
> Hello,
> 
> On 3/27/19 7:05 AM, Masahiko Sawada wrote:
>>>>> 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 
>>>>
>>> I added a comment to explain why transaction logging is rechecked.
>> Umm, I'm inclined to think that we should not disable logging within
>> the transaction. If we allow that, since users can disable the logging
>> within the transaction by setting it to 0 they may think that we can
>> change the rate during the transaction, which is wrong. If we want
>> this behavior we should document it but we can make user not being
>> able to change the rate during the transaction to avoid confusion. And
>> the latter looks more understandable and straightforward. This is
>> different comment what I did before, I'm sorry for confusing you.
> 
> Don't worry, I will change that.
> 
> 
>>
>>>>> As far as I can tell xact_is_sampled is not properly reset in case of
>>>>> errors?
>>>>>
>>> I am not sure if I should disable logging in case of errors. Actually we
>>> have:
>>>
>>> postgres=# set log_transaction_sample_rate to 1;
>>> SET
>>> postgres=# set client_min_messages to 'LOG';
>>> LOG:  duration: 0.392 ms  statement: set client_min_messages to 'LOG';
>>> SET
>>> postgres=# begin;
>>> LOG:  duration: 0.345 ms  statement: begin;
>>> BEGIN
>>> postgres=# select 1;
>>> LOG:  duration: 0.479 ms  statement: select 1;
>>>    ?column?
>>> ----------
>>>           1
>>> (1 row)
>>>
>>> postgres=# select * from missingtable;
>>> ERROR:  relation "missingtable" does not exist
>>> LINE 1: select * from missingtable;
>>>                         ^
>>> postgres=# select 1;
>>> ERROR:  current transaction is aborted, commands ignored until end of
>>> transaction block
>>> postgres=# rollback;
>>> LOG:  duration: 11390.295 ms  statement: rollback;
>>> ROLLBACK
>>>
>>> If I reset xact_is_sampled (after the first error inside
>>> AbortTransaction if I am right), "rollback" statement will not be
>>> logged. I wonder if this "statement" should be logged?
>>>
>>> If the answer is no, I will reset xact_is_sampled in AbortTransaction.
>>>
>> FWIW, I'd prefer to log "rollback" as well so as user can recognize
>> the end of transaction.
> 
> Ok.
> 
>>
>> +       /* Determine if statements are logged in this transaction */
>> +       xact_is_sampled = random() <= log_xact_sample_rate * 
>> MAX_RANDOM_VALUE;
>>
>> If log_xact_sample_rate is 1 we always log all statement in the
>> transaction regardless of value of random(). Similarly if it's 0, we
>> never log. I think we can avoid unnecessary random() call in both case
>> like log_statement_sample_rate does.
> 
> I agree, I will change that.
> 
>>
>>                  {"log_statement_sample_rate", PGC_SUSET, LOGGING_WHEN,
>>                          gettext_noop("Fraction of statements over
>> log_min_duration_statement to log."),
>>                          gettext_noop("If you only want a sample, use a
>> value between 0 (never "
>> -                                                "log) and 1.0 (always 
>> log).")
>> +                                                "log) and 1 (always 
>> log).")
>>                  },
>>                  &log_statement_sample_rate,
>>                  1.0, 0.0, 1.0,
>>                  NULL, NULL, NULL
>>          },
>>
>> This change is not relevant with log_transaction_sample_rate feature
>> but why do we need this change? In postgresql.conf.sample the
>> description of both log_statement_sample_rate and
>> log_transaction_sample_rate use 1.0 instead of 1, like "1.0 logs all
>> statements from all transactions, 0 never logs". If we need this
>> change I think it should be a separate patch.
> 
> 
> Sorry, I changed that, someone suggest using either "0" and "1", or 
> "0.0" and "1.0" but not mixing both. I will remove this change.
> 
> Thanks for your review.
> 
> 
> 

Patch attached with all changes requested.