Content-Type: multipart/mixed; boundary="------------UhmG3J3wLajvwy02CTT5kbGD"
Message-ID: <ea48b857-4e07-dd43-375e-564e13f5bfb2@gmail.com>
Date: Sat, 19 Oct 2024 12:00:00 +0300
MIME-Version: 1.0
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:102.0) Gecko/20100101
 Thunderbird/102.4.2
Subject: Re: BUG #18658: Assert in SerialAdd() due to race condition
Content-Language: en-US
To: Heikki Linnakangas <hlinnaka@iki.fi>, Andrew Bille
 <andrewbille@gmail.com>, pgsql-bugs@lists.postgresql.org
References: <18658-7dab125ec688c70b@postgresql.org>
 <CAJnzarxBO18Ha==H3hX28yz2zd7cVuasXv1wxyJ7ERd9DzJf=Q@mail.gmail.com>
 <5634e3e1-6e82-b883-ac87-52d7e926a04d@gmail.com>
 <ff9d4350-a82d-4a3f-86e5-3948175a9a86@iki.fi>
From: Alexander Lakhin <exclusion@gmail.com>
In-Reply-To: <ff9d4350-a82d-4a3f-86e5-3948175a9a86@iki.fi>
Archived-At: 
 <https://www.postgresql.org/message-id/ea48b857-4e07-dd43-375e-564e13f5bfb2%40gmail.com>
Precedence: bulk

This is a multi-part message in MIME format.
--------------UhmG3J3wLajvwy02CTT5kbGD
Content-Type: text/plain; charset=UTF-8; format=flowed
Content-Transfer-Encoding: 8bit

Hello Heikki,

18.10.2024 23:15, Heikki Linnakangas wrote:
>
> Thanks for the repro, Andrew & Alexander! I was able to reproduce this too. It reproduces very quickly with the script 
> you provided, if you add this sleep to ReleasePredicateLocks():
>
> @@ -3654,6 +3667,8 @@ ReleasePredicateLocks(bool isCommit, bool isReadOnlySafe)
>
>      LWLockRelease(SerializableFinishedListLock);
>
> +    pg_usleep(1000);
> +
>      if (needToClear)
>          ClearOldPredicateLocks();
>
> I think the assertion is too strict. It is normal for tailXid to be invalid in this scenario. The condition is that an 
> XID was added to the finished list, but the global xmin has already advanced past that XID. It gets cleared from the 
> finished list by the ClearOldPredicateLocks() call, but another backend might call SummarizeOldestCommittedSxact() 
> before that.
>
> The attached patch fixes it.
>

Thank you for your attention to this!

I also encountered another (more rare) failure with that script (initially
on REL_16_STABLE, but now I've reproduced this on master too), when it
fails due to ENOSPC. (I could reproduce the failure more or less reliably
by running that script with parallel -j4 using 4 different servers.)

With additional logging added (see attached), I see the following:
2024-10-19 07:34:48.254 UTC [3032898:1][client backend][48/278:0] LOG:  !!!SerialAdd| xid: 19957, 
serialControl->headPage: 4294967295, tailXid: 20491, SERIAL_ENTRIESPERPAGE: 1024, firstZeroPage: 20, targetPage: 19, 
isNewPage: 1
2024-10-19 07:34:48.254 UTC [3032898:2][client backend][48/278:0] STATEMENT:  INSERT INTO t VALUES(42);
2024-10-19 07:34:48.254 UTC [3032898:3][client backend][48/278:0] LOG:  !!!SerialAdd: isNewPage, firstZeroPage: 20, 
targetPage: 19
2024-10-19 07:34:48.254 UTC [3032898:4][client backend][48/278:0] STATEMENT:  INSERT INTO t VALUES(42);
2024-10-19 07:35:05.105 UTC [3032898:5][client backend][48/278:0] ERROR:  could not access status of transaction 0
2024-10-19 07:35:05.105 UTC [3032898:6][client backend][48/278:0] DETAIL:  Could not write to file "pg_serial/11FB3" at 
offset 8192: No space left on device.

That is, if SerialAdd() gets xid preceding tailXid and belonging to a
preceding page, the page zeroing loop just runs until ENOSPC.

Your proposed fix (adjusted for REL_16_STABLE) eliminates the issue for me.
Thank you!

Best regards,
Alexander
--------------UhmG3J3wLajvwy02CTT5kbGD
Content-Type: text/x-patch; charset=UTF-8; name="SerialAdd-debugging.patch"
Content-Disposition: attachment; filename="SerialAdd-debugging.patch"
Content-Transfer-Encoding: base64

ZGlmZiAtLWdpdCBhL3NyYy9iYWNrZW5kL3N0b3JhZ2UvbG1nci9wcmVkaWNhdGUuYyBiL3Ny
Yy9iYWNrZW5kL3N0b3JhZ2UvbG1nci9wcmVkaWNhdGUuYwppbmRleCAxYWY0MTIxM2I0Li40
ZjdjMTU5NzhhIDEwMDY0NAotLS0gYS9zcmMvYmFja2VuZC9zdG9yYWdlL2xtZ3IvcHJlZGlj
YXRlLmMKKysrIGIvc3JjL2JhY2tlbmQvc3RvcmFnZS9sbWdyL3ByZWRpY2F0ZS5jCkBAIC04
NzEsMTIgKzg3MSwxNiBAQCBTZXJpYWxBZGQoVHJhbnNhY3Rpb25JZCB4aWQsIFNlckNvbW1p
dFNlcU5vIG1pbkNvbmZsaWN0Q29tbWl0U2VxTm8pCiAJewogCQlmaXJzdFplcm9QYWdlID0g
U2VyaWFsUGFnZSh0YWlsWGlkKTsKIAkJaXNOZXdQYWdlID0gdHJ1ZTsKK2Vsb2coTE9HLCAi
ISEhU2VyaWFsQWRkfCB4aWQ6ICVkLCBzZXJpYWxDb250cm9sLT5oZWFkUGFnZTogJWQsIHRh
aWxYaWQ6ICVkLCBTRVJJQUxfRU5UUklFU1BFUlBBR0U6ICVsZCwgZmlyc3RaZXJvUGFnZTog
JWQsIHRhcmdldFBhZ2U6ICVkLCBpc05ld1BhZ2U6ICVkIiwKK3hpZCwgc2VyaWFsQ29udHJv
bC0+aGVhZFBhZ2UsIHRhaWxYaWQsIFNFUklBTF9FTlRSSUVTUEVSUEFHRSwgZmlyc3RaZXJv
UGFnZSwgdGFyZ2V0UGFnZSwgaXNOZXdQYWdlKTsKIAl9CiAJZWxzZQogCXsKIAkJZmlyc3Ra
ZXJvUGFnZSA9IFNlcmlhbE5leHRQYWdlKHNlcmlhbENvbnRyb2wtPmhlYWRQYWdlKTsKIAkJ
aXNOZXdQYWdlID0gU2VyaWFsUGFnZVByZWNlZGVzTG9naWNhbGx5KHNlcmlhbENvbnRyb2wt
PmhlYWRQYWdlLAogCQkJCQkJCQkJCQkJdGFyZ2V0UGFnZSk7CitlbG9nKExPRywgIiEhIVNl
cmlhbEFkZHwgeGlkOiAlZCwgc2VyaWFsQ29udHJvbC0+aGVhZFBhZ2U6ICVkLCBmaXJzdFpl
cm9QYWdlOiAlZCwgdGFyZ2V0UGFnZTogJWQsIGlzTmV3UGFnZTogJWQiLAoreGlkLCBzZXJp
YWxDb250cm9sLT5oZWFkUGFnZSwgZmlyc3RaZXJvUGFnZSwgdGFyZ2V0UGFnZSwgaXNOZXdQ
YWdlKTsKIAl9CiAKIAlpZiAoIVRyYW5zYWN0aW9uSWRJc1ZhbGlkKHNlcmlhbENvbnRyb2wt
PmhlYWRYaWQpCkBAIC04ODcsNiArODkxLDcgQEAgU2VyaWFsQWRkKFRyYW5zYWN0aW9uSWQg
eGlkLCBTZXJDb21taXRTZXFObyBtaW5Db25mbGljdENvbW1pdFNlcU5vKQogCiAJaWYgKGlz
TmV3UGFnZSkKIAl7CitlbG9nKExPRywgIiEhIVNlcmlhbEFkZDogaXNOZXdQYWdlLCBmaXJz
dFplcm9QYWdlOiAlZCwgdGFyZ2V0UGFnZTogJWQiLCBmaXJzdFplcm9QYWdlLCB0YXJnZXRQ
YWdlKTsKIAkJLyogSW5pdGlhbGl6ZSBpbnRlcnZlbmluZyBwYWdlcy4gKi8KIAkJd2hpbGUg
KGZpcnN0WmVyb1BhZ2UgIT0gdGFyZ2V0UGFnZSkKIAkJewpAQCAtODk0LDYgKzg5OSw3IEBA
IFNlcmlhbEFkZChUcmFuc2FjdGlvbklkIHhpZCwgU2VyQ29tbWl0U2VxTm8gbWluQ29uZmxp
Y3RDb21taXRTZXFObykKIAkJCWZpcnN0WmVyb1BhZ2UgPSBTZXJpYWxOZXh0UGFnZShmaXJz
dFplcm9QYWdlKTsKIAkJfQogCQlzbG90bm8gPSBTaW1wbGVMcnVaZXJvUGFnZShTZXJpYWxT
bHJ1Q3RsLCB0YXJnZXRQYWdlKTsKK2Vsb2coTE9HLCAiISEhU2VyaWFsQWRkOiBhZnRlciB3
aGlsZSwgc2xvdG5vOiAlZCIsIHNsb3Rubyk7CiAJfQogCWVsc2UKIAkJc2xvdG5vID0gU2lt
cGxlTHJ1UmVhZFBhZ2UoU2VyaWFsU2xydUN0bCwgdGFyZ2V0UGFnZSwgdHJ1ZSwgeGlkKTsK


--------------UhmG3J3wLajvwy02CTT5kbGD--