Repeated requests for feedback in logical standby
От | Magnus Hagander |
---|---|
Тема | Repeated requests for feedback in logical standby |
Дата | |
Msg-id | CABUevExsjROqDcD0A2rnJ6HK6FuKGyewJr3PL12pw85BHFGS2Q@mail.gmail.com обсуждение исходный текст |
Ответы |
Re: Repeated requests for feedback in logical standby
(Nick Cleaton <nick@cleaton.net>)
|
Список | pgsql-bugs |
I've been running some tests, and come across a weird behavior on shutdown with logical replication, 9.5.2. It seems that on shutdown, a lot of extra requests for feedback are sent from the walsender. On my laptop I get about 3-15 requests (different each time), and on a server with a bit more power but still very low activity, the number is simply huge. Basically what happens is: * Replication works fine * I have *zero* activity on the master since it got started, not even a single psql * I issue a fast shutdown on the master * Nothing happens at all for a while * Once pg_recvlogical times out and sends a status message things wake up * The server sends a whole bunch of requests for status, which pg_recvlogical responds to * Eventually things shut down (on the proper server, I've had to kill things because it takes too long - I'm unsure if it ever shuts down) Log output from pg_recvlogical: $ ./pg_recvlogical -v -p 5495 -S trivialslot -o include_transaction=on -v -d postgres --start -f - -P test_decoding 2>&1 | ts '[%Y-%m-%d %H:%M:%S]' [2016-04-12 17:14:31] pg_recvlogical: starting log streaming at 0/0 (slot trivialslot) [2016-04-12 17:14:31] pg_recvlogical: streaming initiated [2016-04-12 17:14:31] pg_recvlogical: confirming write up to 0/0, flush to 0/0 (slot trivialslot) [2016-04-12 17:14:41] pg_recvlogical: confirming write up to 0/18F9DE88, flush to 0/18F9DE88 (slot trivialslot) [2016-04-12 17:14:51] pg_recvlogical: confirming write up to 0/18F9DEF8, flush to 0/18F9DEF8 (slot trivialslot) [2016-04-12 17:14:51] pg_recvlogical: confirming write up to 0/18F9DFA0, flush to 0/18F9DFA0 (slot trivialslot) [2016-04-12 17:14:51] pg_recvlogical: confirming write up to 0/18F9DFA0, flush to 0/18F9DFA0 (slot trivialslot) [2016-04-12 17:14:51] pg_recvlogical: confirming write up to 0/18F9DFA0, flush to 0/18F9DFA0 (slot trivialslot) [2016-04-12 17:14:51] pg_recvlogical: confirming write up to 0/18F9DFA0, flush to 0/18F9DFA0 (slot trivialslot) [2016-04-12 17:14:51] pg_recvlogical: confirming write up to 0/18F9DFA0, flush to 0/18F9DFA0 (slot trivialslot) [2016-04-12 17:14:51] pg_recvlogical: disconnected; waiting 5 seconds to try again In this example, the server has: 2016-04-12 17:14:45 CEST LOG: received fast shutdown request 2016-04-12 17:14:45 CEST LOG: aborting any active transactions 2016-04-12 17:14:45 CEST LOG: autovacuum launcher shutting down 2016-04-12 17:14:45 CEST LOG: shutting down 2016-04-12 17:14:45 CEST LOG: database system is shut down Note how it took a while (6 seconds) for pg_recvlogical to pick up that anything was happening - looks like something might not have been flushed? When running on the server where there's more data it was very clear though - if I break the walsender with gdb, pg_recvlogical stops spitting out debugging messages, and as soon as I "cont" in gdb it starts spitting them out again, so there's a clear connection between the two. And it takes a *lot* more than a few seconds. -- Magnus Hagander Me: http://www.hagander.net/ Work: http://www.redpill-linpro.com/
В списке pgsql-bugs по дате отправления:
Следующее
От: Tom LaneДата:
Сообщение: Re: BUG #14078: Excessive memory growth during nested loop in select