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.