Обсуждение: termination of backend waiting for sync rep generates a junk log message
Hi, In 9.1, the following procedure writes a junk message into the server log; $ initdb -D data $ cat << EOF >> data/postgresql.conf wal_level = hot_standby max_wal_senders = 1 synchronous_standby_names = '*' EOF $ pg_ctl -D data start $ psql -c "create table t (i int)" & $ pg_ctl -D data -m fast stop WARNING: canceling the wait for synchronous replication and terminating connection due to administrator command DETAIL: The transaction has already committed locally, but might not have been replicated to the standby. backend> FATAL: terminating connection due to administrator command The above is the server log messages that I got when I did the procedure. "backend> " is a junk. If a backend is terminated while it's waiting for synchronous replication, whereToSendOutput is set to DestNone. Then, whereToSendOutput=DestNone makes ReadCommand() call InteractiveBackend() which outputs "backend> ". This junk message might mess up the server log monitoring tools. I think it should be removed. The simple fix is to change InteractiveBackend() so that it calls CHECK_FOR_INTERRUPTS() before it outputs "backend> ". Thought? Regards, -- Fujii Masao NIPPON TELEGRAPH AND TELEPHONE CORPORATION NTT Open Source Software Center
On Mon, Oct 17, 2011 at 6:53 AM, Fujii Masao <masao.fujii@gmail.com> wrote:
> WARNING: canceling the wait for synchronous replication and
> terminating connection due to administrator command
> DETAIL: The transaction has already committed locally, but might not
> have been replicated to the standby.
> backend> FATAL: terminating connection due to administrator command
>
> The above is the server log messages that I got when I did the procedure.
> "backend> " is a junk. If a backend is terminated while it's waiting for
> synchronous replication, whereToSendOutput is set to DestNone. Then,
> whereToSendOutput=DestNone makes ReadCommand() call
> InteractiveBackend() which outputs "backend> ".
>
> This junk message might mess up the server log monitoring tools. I think
> it should be removed.
>
> The simple fix is to change InteractiveBackend() so that it calls
> CHECK_FOR_INTERRUPTS() before it outputs "backend> ". Thought?
I'm tempted to say we should do that in PostgresMain() instead, maybe
something like this:
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index 976a832..9e5557c 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -3769,6 +3769,8 @@ PostgresMain(int argc, char *argv[], const char *username)
MemoryContextSwitchTo(MessageContext); MemoryContextResetAndDeleteChildren(MessageContext);
+ CHECK_FOR_INTERRUPTS();
+ initStringInfo(&input_message);
/*
--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company
Robert Haas <robertmhaas@gmail.com> writes:
> On Mon, Oct 17, 2011 at 6:53 AM, Fujii Masao <masao.fujii@gmail.com> wrote:
>> The simple fix is to change InteractiveBackend() so that it calls
>> CHECK_FOR_INTERRUPTS() before it outputs "backend> ". Thought?
> I'm tempted to say we should do that in PostgresMain() instead, maybe
> something like this:
> diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
> index 976a832..9e5557c 100644
> --- a/src/backend/tcop/postgres.c
> +++ b/src/backend/tcop/postgres.c
> @@ -3769,6 +3769,8 @@ PostgresMain(int argc, char *argv[], const char *username)
> MemoryContextSwitchTo(MessageContext);
> MemoryContextResetAndDeleteChildren(MessageContext);
> + CHECK_FOR_INTERRUPTS();
> +
> initStringInfo(&input_message);
> /*
I don't like putting a CHECK_FOR_INTERRUPTS there, because it's way too
late to throw an error for the previous query.
The real problem here is probably that we're overloading the meaning of
whereToSendOutput. The reset of that variable during shutdown was only
ever meant to prevent output from being sent to a no-longer-present
client. It should *not* result in trying to read a query from stdin.
Another question worth asking is how is it that we're getting to
ReadCommand at all, if we have already determined that the client is
gone. Fixing that with an additional CHECK_FOR_INTERRUPTS seems like
a crock.
regards, tom lane
On Tue, Oct 18, 2011 at 5:18 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Robert Haas <robertmhaas@gmail.com> writes:
>> On Mon, Oct 17, 2011 at 6:53 AM, Fujii Masao <masao.fujii@gmail.com> wrote:
>>> The simple fix is to change InteractiveBackend() so that it calls
>>> CHECK_FOR_INTERRUPTS() before it outputs "backend> ". Thought?
>
>> I'm tempted to say we should do that in PostgresMain() instead, maybe
>> something like this:
>
>> diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
>> index 976a832..9e5557c 100644
>> --- a/src/backend/tcop/postgres.c
>> +++ b/src/backend/tcop/postgres.c
>> @@ -3769,6 +3769,8 @@ PostgresMain(int argc, char *argv[], const char *username)
>> MemoryContextSwitchTo(MessageContext);
>> MemoryContextResetAndDeleteChildren(MessageContext);
>
>> + CHECK_FOR_INTERRUPTS();
>> +
>> initStringInfo(&input_message);
>
>> /*
>
> I don't like putting a CHECK_FOR_INTERRUPTS there, because it's way too
> late to throw an error for the previous query.
>
> The real problem here is probably that we're overloading the meaning of
> whereToSendOutput. The reset of that variable during shutdown was only
> ever meant to prevent output from being sent to a no-longer-present
> client. It should *not* result in trying to read a query from stdin.
I think you're right, but am not sure how to fix it.
> Another question worth asking is how is it that we're getting to
> ReadCommand at all, if we have already determined that the client is
> gone. Fixing that with an additional CHECK_FOR_INTERRUPTS seems like
> a crock.
We haven't determined the client is gone; we're trying to close the
connection "unexpectedly". As the comment in SyncRepWaitForLSN
explains:
/* * If a wait for synchronous replication is pending,
we can neither * acknowledge the commit nor raise ERROR or FATAL.
The latter would * lead the client to believe that that the
transaction aborted, which * is not true: it's already committed locally. The
former is no good * either: the client has requested synchronous
replication, and is * entitled to assume that an acknowledged commit is
also replicated, * which might not be true. So in this case we issue a
WARNING (which * some clients may be able to interpret) and shut off
further output. * We do NOT reset ProcDiePending, so that the process
will die after * the commit is cleaned up. */
--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company
Robert Haas <robertmhaas@gmail.com> writes:
> On Tue, Oct 18, 2011 at 5:18 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> Another question worth asking is how is it that we're getting to
>> ReadCommand at all, if we have already determined that the client is
>> gone. �Fixing that with an additional CHECK_FOR_INTERRUPTS seems like
>> a crock.
> We haven't determined the client is gone; we're trying to close the
> connection "unexpectedly". As the comment in SyncRepWaitForLSN
> explains:
> /*
> * If a wait for synchronous replication is pending,
> we can neither
> * acknowledge the commit nor raise ERROR or FATAL.
> The latter would
> * lead the client to believe that that the
> transaction aborted, which
> * is not true: it's already committed locally. The
> former is no good
> * either: the client has requested synchronous
> replication, and is
> * entitled to assume that an acknowledged commit is
> also replicated,
> * which might not be true. So in this case we issue a
> WARNING (which
> * some clients may be able to interpret) and shut off
> further output.
> * We do NOT reset ProcDiePending, so that the process
> will die after
> * the commit is cleaned up.
> */
Hmm. Maybe the real answer is "this code is abusing whereToSendOutput"
(and about six other things besides). I'll try to think of a better
solution, but not tonight.
One thing worth asking is why we're willing to violate half a dozen
different coding rules if we see ProcDiePending, yet we're perfectly
happy to rely on the client understanding a WARNING for the
QueryCancelPending case. Another is whether this whole function isn't
complete BS in the first place, since it appears to be coded on the
obviously-false assumption that nothing it calls can throw elog(ERROR)
--- and of course, if any of those functions do throw ERROR, all the
argumentation here goes out the window.
regards, tom lane
On Tue, Oct 18, 2011 at 11:27 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote: > One thing worth asking is why we're willing to violate half a dozen > different coding rules if we see ProcDiePending, yet we're perfectly > happy to rely on the client understanding a WARNING for the > QueryCancelPending case. Another is whether this whole function isn't > complete BS in the first place, since it appears to be coded on the > obviously-false assumption that nothing it calls can throw elog(ERROR) > --- and of course, if any of those functions do throw ERROR, all the > argumentation here goes out the window. Well, there is a general problem that anything which throws an ERROR too late in the commit path is Evil; and sync rep makes that worse to the extent that it adds more stuff late in the commit path, but it didn't invent the problem. What it did do is add stuff late in the commit path that can block for a potentially unbounded period of time, and I don't see that there are any solutions to that problem that aren't somewhat grotty. -- Robert Haas EnterpriseDB: http://www.enterprisedb.com The Enterprise PostgreSQL Company
Robert Haas <robertmhaas@gmail.com> writes:
> On Tue, Oct 18, 2011 at 11:27 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> One thing worth asking is why we're willing to violate half a dozen
>> different coding rules if we see ProcDiePending, yet we're perfectly
>> happy to rely on the client understanding a WARNING for the
>> QueryCancelPending case. �Another is whether this whole function isn't
>> complete BS in the first place, since it appears to be coded on the
>> obviously-false assumption that nothing it calls can throw elog(ERROR)
>> --- and of course, if any of those functions do throw ERROR, all the
>> argumentation here goes out the window.
> Well, there is a general problem that anything which throws an ERROR
> too late in the commit path is Evil; and sync rep makes that worse to
> the extent that it adds more stuff late in the commit path, but it
> didn't invent the problem. What it did do is add stuff late in the
> commit path that can block for a potentially unbounded period of time,
> and I don't see that there are any solutions to that problem that
> aren't somewhat grotty.
No doubt, but fantasizing about what you are or are not controlling
doesn't help ... and AFAICT this code is mostly fantasy. Anyway,
I don't have a better proposal right offhand; will think about it.
regards, tom lane
Robert Haas <robertmhaas@gmail.com> writes:
> On Tue, Oct 18, 2011 at 11:27 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> One thing worth asking is why we're willing to violate half a dozen
>> different coding rules if we see ProcDiePending, yet we're perfectly
>> happy to rely on the client understanding a WARNING for the
>> QueryCancelPending case. �Another is whether this whole function isn't
>> complete BS in the first place, since it appears to be coded on the
>> obviously-false assumption that nothing it calls can throw elog(ERROR)
>> --- and of course, if any of those functions do throw ERROR, all the
>> argumentation here goes out the window.
> Well, there is a general problem that anything which throws an ERROR
> too late in the commit path is Evil; and sync rep makes that worse to
> the extent that it adds more stuff late in the commit path, but it
> didn't invent the problem. What it did do is add stuff late in the
> commit path that can block for a potentially unbounded period of time,
> and I don't see that there are any solutions to that problem that
> aren't somewhat grotty.
After further reflection, you're right that all sync rep is really doing
is extending the time duration of the interval wherein clients will have
a hard time telling whether the commit occurred or not. It's always
been the case that if a cancel/die interrupt occurs during
CommitTransaction, that will get serviced at the RESUME_INTERRUPTS call
at the end, and the client will see an apparent failure even though the
transaction was committed. Even without that, an interrupt occurring
just after this code sequence, but before we reach the point of sending
a command-complete response message, is going to result in client
confusion, and there's very little we can do about that.
I think what we should do in SyncRepWaitForLSN is just send a warning
and abandon waiting. Trying to fool with the interrupt response
behavior beyond that is simply broken, and it doesn't help any that we
chose to break it in two different, but equally indefensible, ways for
cancel versus die interrupts.
It would help BTW for the warning to have its own SQLSTATE, if we're
imagining that "some clients may be able to interpret" it. Also, this
code is supposing that it must be called within a HOLD_INTERRUPTS
context, but it doesn't look to me like that is being done for the
various calls from twophase.c.
regards, tom lane
Robert Haas <robertmhaas@gmail.com> writes:
> Well, there is a general problem that anything which throws an ERROR
> too late in the commit path is Evil; and sync rep makes that worse to
> the extent that it adds more stuff late in the commit path, but it
> didn't invent the problem.
BTW, it strikes me that if we want to do something about that, it ought
to be possible; but it has to be built into error handling, not a
localized hack for sync rep.
Consider a design along these lines: we invent a global flag that gets
set at some appropriate point in RecordTransactionCommit (probably right
where we exit the commit critical section) and is not cleared until we
send a suitable message to the client --- I think either
command-complete or an error message would qualify, but that would have
to be analyzed more carefully than I've done so far. If elog.c is told
to send an error message while this flag is set, then it does something
special to inform the client that this was a post-commit error and the
xact is in fact committed.
My inclination for the "something special" would be to add a new error
message field, but that could be difficult for clients to examine
depending on what sort of driver infrastructure they're dealing with.
You could also imagine emitting a separate NOTICE or WARNING message,
which is analogous to the current hack in SyncRepWaitForLSN, but seems
pretty ugly because it requires clients to re-associate that event with
the later error message. (But it might be worth doing anyway for human
users, even if we provide a different flag mechanism that is intended
for program consumption.) Or maybe we could override the SQLSTATE with
some special value. Or something else.
Given infrastructure like this, it would be reasonable for
SyncRepWaitForLSN to just throw an ERROR if it gets an interrupt,
instead of trying to kluge its own solution.
regards, tom lane
On Mon, Oct 24, 2011 at 10:05 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> as it seems to me that any
>> client that is paranoid enough to care about sync rep had better
>> already be handling the case of a connection loss during commit.
>
> Agreed, but that is a problem that by definition we can't help with.
> Also, the issue with connection loss is that you really can't know
> whether your transaction got committed without reconnecting and looking
> for evidence. There is no reason at all to inject such uncertainty
> into the cancel-SyncRepWaitForLSN case. We know the transaction got
> committed,
I disagree. The whole point of synchronous replication is that the
user is worried about the case where the primary goes away just after
the commit is acknowledged to the client. Consider the following
scenario: Someone has determined that it can't be reached from 90% of
the corporate Internet, but the synchronous standby, which is
naturally on another network, still has connectivity. So they log
into the master and perform a fast shutdown. When they reconnect, the
connection pooler (or other mechanism) redirects their connection to
the standby, which has sense been promoted. ISTM that the client had
darn well better go search for hard evidence about the transaction
state.
>> But I think that throwing an ERROR is likely to cause a LOT of client
>> breakage, even if you have some special (human-invisible?) flag that
>> indicates that you don't really mean it. If we must do something
>> other than simulating a server disconnect, letting the command
>> completion message go through and annotating it with a NOTICE or
>> WARNING seems preferable.
>
> I think you're thinking narrowly of the SyncRepWaitForLSN case. What
> I'm trying to point out is that there's a boatload of post-commit code
> which is capable of sometimes throwing errors, and that's not ever
> going to go away completely.
>
> It might be that it'd work to deal with this by reducing the reported
> strength of all such cases from ERROR to WARNING. Not sure that that's
> a good idea, but it might work.
It's hard to be sure that a systematic approach will work. For
example, if we fail to can't nuke a memory context for some reason, it
wouldn't be utterly crazy to just ignore the problem and try to
soldier on. We've probably leaked some memory, but oh well. If we've
failed to release a heavyweight lock we had better call
LockReleaseAll() somehow, but the details of what gets sent to the
client are negotiable and a WARNING is probably fine. On the other
hand, if we experienced some failure that affects our ability to make
the transaction globally visible (like we wrote the commit record but
then fail trying to acquire ProcArrayLock to clear our xmin), it's
hard to believe that anything other than PANIC is enough.
Because of that and similar cases elsewhere, including for example
inside the lock manager, I've long been feeling grumpy about this:
/* Ensure we will have room to remember the lock */ if (num_held_lwlocks >= MAX_SIMUL_LWLOCKS)
elog(ERROR, "too many LWLocks taken");
It seems to me that the idea that the abort path is going to be able
to recover from that situation is wildly optimistic. Fortunately, our
coding practices are good enough that I think it never happens anyway,
but if it does it should surely PANIC.
--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company
On Sun, Oct 23, 2011 at 6:34 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote: > Robert Haas <robertmhaas@gmail.com> writes: >> Well, there is a general problem that anything which throws an ERROR >> too late in the commit path is Evil; and sync rep makes that worse to >> the extent that it adds more stuff late in the commit path, but it >> didn't invent the problem. > > BTW, it strikes me that if we want to do something about that, it ought > to be possible; but it has to be built into error handling, not a > localized hack for sync rep. > > Consider a design along these lines: we invent a global flag that gets > set at some appropriate point in RecordTransactionCommit (probably right > where we exit the commit critical section) and is not cleared until we > send a suitable message to the client --- I think either > command-complete or an error message would qualify, but that would have > to be analyzed more carefully than I've done so far. If elog.c is told > to send an error message while this flag is set, then it does something > special to inform the client that this was a post-commit error and the > xact is in fact committed. > > My inclination for the "something special" would be to add a new error > message field, but that could be difficult for clients to examine > depending on what sort of driver infrastructure they're dealing with. > You could also imagine emitting a separate NOTICE or WARNING message, > which is analogous to the current hack in SyncRepWaitForLSN, but seems > pretty ugly because it requires clients to re-associate that event with > the later error message. (But it might be worth doing anyway for human > users, even if we provide a different flag mechanism that is intended > for program consumption.) Or maybe we could override the SQLSTATE with > some special value. Or something else. > > Given infrastructure like this, it would be reasonable for > SyncRepWaitForLSN to just throw an ERROR if it gets an interrupt, > instead of trying to kluge its own solution. I actually think that emitting a NOTICE or WARNING and then slamming the connection shut is quite elegant, as it seems to me that any client that is paranoid enough to care about sync rep had better already be handling the case of a connection loss during commit. I realize that handling query cancellation in a somewhat different way is a wart, though, and I'm not necessarily opposed to changing the behavior. But I think that throwing an ERROR is likely to cause a LOT of client breakage, even if you have some special (human-invisible?) flag that indicates that you don't really mean it. If we must do something other than simulating a server disconnect, letting the command completion message go through and annotating it with a NOTICE or WARNING seems preferable. -- Robert Haas EnterpriseDB: http://www.enterprisedb.com The Enterprise PostgreSQL Company
Robert Haas <robertmhaas@gmail.com> writes:
> On Sun, Oct 23, 2011 at 6:34 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> BTW, it strikes me that if we want to do something about that, it ought
>> to be possible; but it has to be built into error handling, not a
>> localized hack for sync rep.
> I actually think that emitting a NOTICE or WARNING and then slamming
> the connection shut is quite elegant,
No, it's a horrid crock, whose only saving grace is that it was
implementable with two or three lines localized to SyncRepWaitForLSN
... or at least, we thought that until Fujii-san started pointing out
the bugs in it. It's not convenient for clients at all, it does not fit
well into the backend structure (which is the reason for the bugs), and
it forces session termination unnecessarily, or at least it would if
we'd been consistent and applied the method to query-cancel as well.
> as it seems to me that any
> client that is paranoid enough to care about sync rep had better
> already be handling the case of a connection loss during commit.
Agreed, but that is a problem that by definition we can't help with.
Also, the issue with connection loss is that you really can't know
whether your transaction got committed without reconnecting and looking
for evidence. There is no reason at all to inject such uncertainty
into the cancel-SyncRepWaitForLSN case. We know the transaction got
committed, and there's no reason to make the client guess about that,
nor to make it parse WARNING messages for which we didn't even get the
assignment of a unique SQLSTATE right (thus making the problem
insoluble anyhow).
> But I think that throwing an ERROR is likely to cause a LOT of client
> breakage, even if you have some special (human-invisible?) flag that
> indicates that you don't really mean it. If we must do something
> other than simulating a server disconnect, letting the command
> completion message go through and annotating it with a NOTICE or
> WARNING seems preferable.
I think you're thinking narrowly of the SyncRepWaitForLSN case. What
I'm trying to point out is that there's a boatload of post-commit code
which is capable of sometimes throwing errors, and that's not ever
going to go away completely.
It might be that it'd work to deal with this by reducing the reported
strength of all such cases from ERROR to WARNING. Not sure that that's
a good idea, but it might work.
regards, tom lane
Re: termination of backend waiting for sync rep generates a junk log message
От
"Kevin Grittner"
Дата:
Tom Lane <tgl@sss.pgh.pa.us> wrote: > It might be that it'd work to deal with this by reducing the > reported strength of all such cases from ERROR to WARNING. Not > sure that that's a good idea, but it might work. Throwing an error on commit of a transaction when its work has actually been persisted seems as bad as failing to persist the work of a transaction when the commit appears successful. If we know we have met the persistence guarantees and some problem occurs after that, then it seems to me we should issue a warning and indicate success. If we don't know whether the work will be persisted, it seems to me we can block until we find out (if that's feasible) or break the connection without indicating one way or the other. The work of the transaction must either all be persisted or not (I'm assuming this isn't a problem here), and any user must be prepared to deal with a broken connection before response on a commit attempt. I don't know whether changing all failures beyond the persistence point in a commit to warnings is sufficient, but I think it is required for anything which doesn't break the connection. -Kevin