Message-ID: <5538A018.9030608@iki.fi>
Date: Thu, 23 Apr 2015 10:32:40 +0300
From: Heikki Linnakangas <hlinnaka@iki.fi>
Reply-To: hlinnaka@iki.fi
User-Agent: Mozilla/5.0 (X11; Linux x86_64;
 rv:31.0) Gecko/20100101 Icedove/31.6.0
MIME-Version: 1.0
To: Michael Paquier <michael.paquier@gmail.com>, grant@amazon.com
CC: pgsql-bugs@postgresql.org
Subject: Re: BUG #13128: Postgres deadlock on startup failure when
 max_prepared_transactions is not sufficiently high.
References: <20150422220940.5216.95902@wrigleys.postgresql.org>
 <CAB7nPqT5y9892TzLRzZ+CxvG6FwA206SoXcSbsvP6b-i=n3AUw@mail.gmail.com>
In-Reply-To: 
 <CAB7nPqT5y9892TzLRzZ+CxvG6FwA206SoXcSbsvP6b-i=n3AUw@mail.gmail.com>
Content-Type: multipart/mixed; boundary="------------030206080903020108070109"
Precedence: bulk
Sender: pgsql-bugs-owner@postgresql.org

This is a multi-part message in MIME format.
--------------030206080903020108070109
Content-Type: text/plain; charset=windows-1252; format=flowed
Content-Transfer-Encoding: 7bit

On 04/23/2015 04:20 AM, Michael Paquier wrote:
> On Thu, Apr 23, 2015 at 7:09 AM,  <grant@amazon.com> wrote:
>> 1.       Set max_prepared_transactions to 2 in postgresql.conf.
>> 2.       start Postgres.
>> 3.       Create two uncommitted prepared transactions: BEGIN; PREPARE
>> TRANSACTION 'test1'; BEGIN; PREPARE TRANSACTION 'test2';
>> 4.       Set max_prepared_transactions to 1 in postgresql.conf.
>> 5.       Restart Postgres again.
>>
>> At this point the startup will fail with a fatal but the postmaster process
>> keeps running.
>>
>> LOG:  database system was interrupted; last known up at 2015-04-16 17:19:56
>> PDT
>> LOG:  database system was not properly shut down; automatic recovery in
>> progress
>> LOG:  record with zero length at 0/1826C70
>> LOG:  redo is not required
>> LOG:  recovering prepared transaction 1685
>> LOG:  recovering prepared transaction 1683
>> FATAL:  maximum number of prepared transactions reached
>> HINT:  Increase max_prepared_transactions (currently 1).
>>
>> Looks like their may be a LWLock that is not correctly getting released
>> which causes the process to hang rather then exit.
>
> Yep, the startup process remains stuck here, so we should release the
> lock before issuing ERROR in twophase.c:

As Tom noted in the other thread, that is not generally required. 
LWLockReleaseAll() is call during process exit.

Hmm. What happens here is that when the startup process is about to 
exit, because of the ERROR, it calls the shmem-exit hooks. 
AtProcExit_Twophase sees that MyLockedGxact != NULL, and it tries to 
clear MyLockedGxact->locking_backend to release the entry.

That's bogus. MyLockedGxact != NULL indicates that the backend is 
currently operating on the entry. But that's not the case at that point 
during RecoverPreparedTransactions(). It has already completed 
recovering the previous transaction, and has not yet locked a 
GlobalTransaction entry for the next one.

RecoverPreparedTransactions() should clear MyLockedGxact after it has 
recovered the transaction, after the StandbyReleaseLockTree() call. 
That's analogous to the normal PREPARE TRANSACTION path, in 
PrepareTransaction(), where we call PostPrepare_Twophase() after 
releasing the locks.

Attached is a patch for that. I introduced this bug in commit 
bb38fb0d43c8d7ff54072bfd8bd63154e536b384, which added the proc-exit hook 
and the call PostPrepare_Twophase(), so unless you see more bugs in 
this, I'll commit and backpatch this to all versions.

- Heikki


--------------030206080903020108070109
Content-Type: application/x-patch;
 name="fix-recover-twophase-xacts-1.patch"
Content-Transfer-Encoding: base64
Content-Disposition: attachment; filename="fix-recover-twophase-xacts-1.patch"

ZGlmZiAtLWdpdCBhL3NyYy9iYWNrZW5kL2FjY2Vzcy90cmFuc2FtL3R3b3Bo
YXNlLmMgYi9zcmMvYmFja2VuZC9hY2Nlc3MvdHJhbnNhbS90d29waGFzZS5j
CmluZGV4IGI4NWE2NjYuLjNhYzMzOWIgMTAwNjQ0Ci0tLSBhL3NyYy9iYWNr
ZW5kL2FjY2Vzcy90cmFuc2FtL3R3b3BoYXNlLmMKKysrIGIvc3JjL2JhY2tl
bmQvYWNjZXNzL3RyYW5zYW0vdHdvcGhhc2UuYwpAQCAtMjA1NCw2ICsyMDU0
LDEyIEBAIFJlY292ZXJQcmVwYXJlZFRyYW5zYWN0aW9ucyh2b2lkKQogCQkJ
aWYgKEluSG90U3RhbmRieSkKIAkJCQlTdGFuZGJ5UmVsZWFzZUxvY2tUcmVl
KHhpZCwgaGRyLT5uc3VieGFjdHMsIHN1YnhpZHMpOwogCisJCQkvKgorCQkJ
ICogV2UncmUgZG9uZSB3aXRoIHJlY292ZXJpbmcgdGhpcyB0cmFuc2FjdGlv
bi4gQ2xlYXIgTXlMb2NrZWRHeGFjdCwKKwkJCSAqIGxpa2Ugd2UgZG8gaW4g
UHJlcGFyZVRyYW5zYWN0aW9uKCkgZHVyaW5nIG5vcm1hbCBvcGVyYXRpb24u
CisJCQkgKi8KKwkJCVBvc3RQcmVwYXJlX1R3b3BoYXNlKCk7CisKIAkJCXBm
cmVlKGJ1Zik7CiAJCX0KIAl9Cg==

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


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

--------------030206080903020108070109--