Re: Log a sample of transactions

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.