Message-ID: <1486805889.24568.96.camel@credativ.de>
Subject: gitlab post-mortem: pg_basebackup waiting for checkpoint
From: Michael Banck <michael.banck@credativ.de>
To: Pg Hackers <pgsql-hackers@postgresql.org>
Date: Sat, 11 Feb 2017 10:38:09 +0100
Organization: credativ GmbH
Content-Type: multipart/mixed; boundary="=-cCnxyn1VU7wamcyajv6f"
Mime-Version: 1.0
Precedence: bulk
Sender: pgsql-hackers-owner@postgresql.org


--=-cCnxyn1VU7wamcyajv6f
Content-Type: text/plain; charset="UTF-8"
Content-Transfer-Encoding: 8bit

Hi,

one take-away from the Gitlab Post-Mortem[1] appears to be that after
their secondary lost replication, they were confused about what
pg_basebackup was doing when they tried to rebuild it. It just sat there
and did nothing (even with --verbose), so they assumed something was
wrong with either the primary or the connection, and restarted it
several times.

AFAICT, it turns out the checkpoint was written on the master (they
probably did not use -c fast), but this wasn't obvious to them:

"One of the engineers went to the secondary and wiped the data
directory, then ran pg_basebackup. Unfortunately pg_basebackup would
hang, producing no meaningful output, despite the --verbose option being
set."

[...]

"Unfortunately this did not resolve the problem of pg_basebackup not
starting replication immediately. One of the engineers decided to run it
with strace to see what it was blocking on. strace showed that
pg_basebackup was hanging in a poll call, but that did not provide any
other meaningful information that might have explained why."

[...]

"It would later be revealed by another engineer (who wasn't around at
the time) that this is normal behavior: pg_basebackup will wait for the
primary to start sending over replication data and it will sit and wait
silently until that time. Unfortunately this was not clearly documented
in our engineering runbooks nor in the official pg_basebackup document."

ISTM that even with WAL streaming, nothing would be written on the
client server until the checkpoint is complete, as do_pg_start_backup()
runs the checkpoint and only returns the starting WAL location
afterwards.

The attached (untested) patch is to kick of a discussion on how to
improve the situation, it is supposed to mention the checkpoint when
--verbose is used and adds a paragraph about the checkpoint being run to
the Notes section of the documentation.


Michael

[1]https://about.gitlab.com/2017/02/10/postmortem-of-database-outage-of-january-31/

-- 
Michael Banck
Projektleiter / Senior Berater
Tel.: +49 2166 9901-171
Fax:  +49 2166 9901-100
Email: michael.banck@credativ.de

credativ GmbH, HRB Mönchengladbach 12080
USt-ID-Nummer: DE204566209
Trompeterallee 108, 41189 Mönchengladbach
Geschäftsführung: Dr. Michael Meskes, Jörg Folz, Sascha Heuer


--=-cCnxyn1VU7wamcyajv6f
Content-Disposition: attachment; filename="pg_basebackup.patch"
Content-Type: text/x-patch; name="pg_basebackup.patch"; charset="UTF-8"
Content-Transfer-Encoding: base64

ZGlmZiAtLWdpdCBhL2RvYy9zcmMvc2dtbC9yZWYvcGdfYmFzZWJhY2t1cC5z
Z21sIGIvZG9jL3NyYy9zZ21sL3JlZi9wZ19iYXNlYmFja3VwLnNnbWwKaW5k
ZXggYzlkZDYyYy4uYTI5OGU1YyAxMDA2NDQKLS0tIGEvZG9jL3NyYy9zZ21s
L3JlZi9wZ19iYXNlYmFja3VwLnNnbWwKKysrIGIvZG9jL3NyYy9zZ21sL3Jl
Zi9wZ19iYXNlYmFja3VwLnNnbWwKQEAgLTY2MCw2ICs2NjAsMTQgQEAgUG9z
dGdyZVNRTCBkb2N1bWVudGF0aW9uCiAgIDx0aXRsZT5Ob3RlczwvdGl0bGU+
CiAKICAgPHBhcmE+CisgICBBdCB0aGUgYmVnaW5uaW5nIG9mIHRoZSBiYWNr
dXAsIGEgY2hlY2twb2ludCBuZWVkcyB0byBiZSB3cml0dGVuIG9uIHRoZQor
ICAgc2VydmVyIHRoZSBiYWNrdXAgaXMgdGFrZW4gZnJvbS4gIEVzcGVjaWFs
bHkgaWYgdGhlIG9wdGlvbgorICAgPGxpdGVyYWw+LS1jaGVja3BvaW50PWZh
c3Q8L2xpdGVyYWw+IGlzIG5vdCB1c2VkLCB0aGlzIGNhbiB0YWtlIHNvbWUg
dGltZQorICAgZHVyaW5nIHdoaWNoIDxhcHBsaWNhdGlvbj5wZ19iYXNlYmFj
a3VwPC9hcHBsaWNhdGlvbj4gd2lsbCBiZSBpZGxlIG9uIHRoZQorICAgc2Vy
dmVyIGl0IGlzIHJ1bm5pbmcgb24uCisgIDwvcGFyYT4KKworICA8cGFyYT4K
ICAgIFRoZSBiYWNrdXAgd2lsbCBpbmNsdWRlIGFsbCBmaWxlcyBpbiB0aGUg
ZGF0YSBkaXJlY3RvcnkgYW5kIHRhYmxlc3BhY2VzLAogICAgaW5jbHVkaW5n
IHRoZSBjb25maWd1cmF0aW9uIGZpbGVzIGFuZCBhbnkgYWRkaXRpb25hbCBm
aWxlcyBwbGFjZWQgaW4gdGhlCiAgICBkaXJlY3RvcnkgYnkgdGhpcmQgcGFy
dGllcywgZXhjZXB0IGNlcnRhaW4gdGVtcG9yYXJ5IGZpbGVzIG1hbmFnZWQg
YnkKZGlmZiAtLWdpdCBhL3NyYy9iaW4vcGdfYmFzZWJhY2t1cC9wZ19iYXNl
YmFja3VwLmMgYi9zcmMvYmluL3BnX2Jhc2ViYWNrdXAvcGdfYmFzZWJhY2t1
cC5jCmluZGV4IGI2NDYzZmEuLmFlMThjMTYgMTAwNjQ0Ci0tLSBhL3NyYy9i
aW4vcGdfYmFzZWJhY2t1cC9wZ19iYXNlYmFja3VwLmMKKysrIGIvc3JjL2Jp
bi9wZ19iYXNlYmFja3VwL3BnX2Jhc2ViYWNrdXAuYwpAQCAtMTc1NCw2ICsx
NzU0LDkgQEAgQmFzZUJhY2t1cCh2b2lkKQogCWlmIChtYXhyYXRlID4gMCkK
IAkJbWF4cmF0ZV9jbGF1c2UgPSBwc3ByaW50ZigiTUFYX1JBVEUgJXUiLCBt
YXhyYXRlKTsKIAorCWlmICh2ZXJib3NlKQorCQlmcHJpbnRmKHN0ZGVyciwg
IiVzOiBpbml0aWF0aW5nIGJhc2UgYmFja3VwLCB3YWl0aW5nIGZvciBjaGVj
a3BvaW50IHRvIGNvbXBsZXRlXG4iLCBwcm9nbmFtZSk7CisKIAliYXNlYmtw
ID0KIAkJcHNwcmludGYoIkJBU0VfQkFDS1VQIExBQkVMICclcycgJXMgJXMg
JXMgJXMgJXMgJXMiLAogCQkJCSBlc2NhcGVkX2xhYmVsLApAQCAtMTc3MSw2
ICsxNzc0LDkgQEAgQmFzZUJhY2t1cCh2b2lkKQogCQlkaXNjb25uZWN0X2Fu
ZF9leGl0KDEpOwogCX0KIAorCWlmICh2ZXJib3NlKQorCQlmcHJpbnRmKHN0
ZGVyciwgIiVzOiBjaGVja3BvaW50IGNvbXBsZXRlZFxuIiwgcHJvZ25hbWUp
OworCiAJLyoKIAkgKiBHZXQgdGhlIHN0YXJ0aW5nIHhsb2cgcG9zaXRpb24K
IAkgKi8K

--=-cCnxyn1VU7wamcyajv6f
Content-Type: text/plain
Content-Disposition: inline
Content-Transfer-Encoding: 8bit
MIME-Version: 1.0


-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

--=-cCnxyn1VU7wamcyajv6f--