Re: Log a sample of transactions

From: Masahiko Sawada <sawada(dot)mshk(at)gmail(dot)com>
To: Adrien NAYRAT <adrien(dot)nayrat(at)anayrat(dot)info>
Cc: Andres Freund <andres(at)anarazel(dot)de>, "Kuroda, Hayato" <kuroda(dot)hayato(at)jp(dot)fujitsu(dot)com>, "pgsql-hackers(at)lists(dot)postgresql(dot)org" <pgsql-hackers(at)lists(dot)postgresql(dot)org>
Subject: Re: Log a sample of transactions
Date: 2019-03-27 06:05:06
Message-ID: CAD21AoB9+y8N4+Fan-ne-_7J5yTybPttxeVKfwUocKp4zT1vNQ@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

Thank you for updating the patch!

On Sat, Mar 2, 2019 at 3:18 AM Adrien NAYRAT <adrien(dot)nayrat(at)anayrat(dot)info> wrote:
>
> Hello,
>
> On 2/15/19 3:24 PM, Adrien NAYRAT wrote:
> > On 2/14/19 9:14 PM, Andres Freund wrote:
> >> 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
>
> Warning added.
>
> >> 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
>
> Fixed
>
> >> 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.

>
> >>
> >> 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.

+ /* 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.

{"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.

--
Regards,

--
Masahiko Sawada
NIPPON TELEGRAPH AND TELEPHONE CORPORATION
NTT Open Source Software Center

In response to

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Tsunakawa, Takayuki 2019-03-27 06:17:08 RE: Libpq support to connect to standby server as priority
Previous Message Chapman Flack 2019-03-27 05:53:20 Re: Fix XML handling with DOCTYPE