Content-Type: multipart/mixed; boundary="------------9LU7uB059OesdM0j2LCf0l8c"
Message-ID: <e9eca7ab-3624-4054-9c93-bd115049aab8@illuminatedcomputing.com>
Date: Tue, 28 Jan 2025 22:34:33 -0800
MIME-Version: 1.0
User-Agent: Mozilla Thunderbird
Subject: Re: SQL:2011 application time
To: Peter Eisentraut <peter@eisentraut.org>
Cc: Tom Lane <tgl@sss.pgh.pa.us>, jian he <jian.universality@gmail.com>,
 PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>,
 vignesh C <vignesh21@gmail.com>
References: <CA+renyUApHgSZF9-nd-a0+OPGharLQLO=mDHcY4_qQ0+noCUVg@mail.gmail.com>
 <6dc196d4-8853-49d7-8dd3-e391058451c1@eisentraut.org>
 <bf6b3fc5-b1c2-4fdf-ad27-5de45770c58c@illuminatedcomputing.com>
 <66e47fc0-77b7-4763-9b70-5c0b7ff15f21@eisentraut.org>
 <a2ee0c1a-5ef0-43ab-897c-b56adb25b34f@illuminatedcomputing.com>
 <333d3886-b737-45c3-93f4-594c96bb405d@eisentraut.org>
 <e8e51e74-10d7-410d-a1d1-8ec681d8436a@eisentraut.org>
 <f4056005-0fb7-417a-bcb3-e704f9aeadc3@illuminatedcomputing.com>
 <6a2247d9-461d-4b0a-b692-f0f3c0fab27f@eisentraut.org>
 <8f995a4c-64e3-40cd-bfed-06b54a280d36@illuminatedcomputing.com>
 <0832f18d-523f-4c15-acb0-338a785150c5@illuminatedcomputing.com>
 <5f0c25de-2c13-4fb5-a4df-a1e03c43cd14@illuminatedcomputin! g.com>
 <1b45f81d-4e99-4813-a2c6-72bf5fd80980@eisentraut.org>
 <3611540.1737518430@sss.pgh.pa.us>
 <9bb3eea7-820f-4932-92cb-cb564fc44caf@eisentraut.org>
 <bca3e7e6-ac1f-476d-9725-d6aec9100ed0@illuminatedcomputing.com>
 <23923ad9-a468-4c2e-8926-e47d15d1eb23@eisentraut.org>
Content-Language: en-US
From: Paul Jungwirth <pj@illuminatedcomputing.com>
In-Reply-To: <23923ad9-a468-4c2e-8926-e47d15d1eb23@eisentraut.org>
Archived-At: <https://www.postgresql.org/message-id/e9eca7ab-3624-4054-9c93-bd115049aab8%40illuminatedcomputing.com>
Precedence: bulk

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

On 1/27/25 07:47, Peter Eisentraut wrote:
 > On 24.01.25 03:55, Tom Lane wrote:
 >> I've now run an exhaustive search through the last three months of
 >> buildfarm runs, and found just one additional instance of the same
 >> failure.  The three matches are
 >>
 >> https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=calliphoridae&dt=2025-01-22%2005%3A49%3A08
 >> https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=indri&dt=2025-01-22%2001%3A29%3A35
 >> https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=mylodon&dt=2025-01-22%2001%3A17%3A14
 >>
 >> Since those are all post-1772d554b0, it's difficult to avoid the
 >> conclusion that that either introduced the error or allowed a
 >> pre-existing problem to become visible.
 >
 > I found a few more in the bowels of various Cirrus CI jobs:
 >
 > https://cirrus-ci.com/task/5125479033733120
 > -> https://api.cirrus-ci.com/v1/artifact/task/5125479033733120/testrun/build/testrun/regress/
 > regress/regression.diffs
 >
 > https://cirrus-ci.com/task/4562529080311808
 > -> https://api.cirrus-ci.com/v1/artifact/task/4562529080311808/log/src/test/recovery/tmp_check/
 > regression.diffs
 >
 > https://cirrus-ci.com/task/5985049025183744
 > -> https://api.cirrus-ci.com/v1/artifact/task/5985049025183744/log/src/bin/pg_upgrade/tmp_check/
 > regression.diffs
 >
 > https://cirrus-ci.com/task/4702566639992832
 > -> https://api.cirrus-ci.com/v1/artifact/task/4702566639992832/log/src/test/recovery/tmp_check/
 > regression.diffs

Thanks to you both for finding some more examples! This answers one question I've been wondering 
about: Why do we get this failure for range types . . .:

```
diff -U3 /tmp/cirrus-ci-build/src/test/regress/expected/without_overlaps.out 
/tmp/cirrus-ci-build/src/test/recovery/tmp_check/results/without_overlaps.out
--- /tmp/cirrus-ci-build/src/test/regress/expected/without_overlaps.out	2025-01-25 
03:14:11.906404866 +0000
+++ /tmp/cirrus-ci-build/src/test/recovery/tmp_check/results/without_overlaps.out	2025-01-25 
03:21:08.218167913 +0000
@@ -1792,8 +1792,6 @@
    SET valid_at = CASE WHEN lower(valid_at) = '2018-01-01' THEN daterange('2018-01-01', '2018-01-05')
                        WHEN lower(valid_at) = '2018-02-01' THEN daterange('2018-01-05', 
'2018-03-01') END
    WHERE id = '[6,7)';
-ERROR:  update or delete on table "temporal_rng" violates RESTRICT setting of foreign key 
constraint "temporal_fk_rng2rng_fk" on table "temporal_fk_rng2rng"
-DETAIL:  Key (id, valid_at)=([6,7), [2018-01-01,2018-02-01)) is referenced from table 
"temporal_fk_rng2rng".
  -- a PK update that fails because both are referenced (even before commit):
  BEGIN;
    ALTER TABLE temporal_fk_rng2rng
```

. . . but never a failure later in the file for the same scenario with multiranges? But Peter's 
links [1] now include an example of that too:

```
diff -U3 /tmp/cirrus-ci-build/src/test/regress/expected/without_overlaps.out 
/tmp/cirrus-ci-build/src/bin/pg_upgrade/tmp_check/results/without_overlaps.out
--- /tmp/cirrus-ci-build/src/test/regress/expected/without_overlaps.out	2025-01-25 
04:31:18.353128126 +0000
+++ /tmp/cirrus-ci-build/src/bin/pg_upgrade/tmp_check/results/without_overlaps.out	2025-01-25 
04:35:22.020363327 +0000
@@ -2311,8 +2311,6 @@
    SET valid_at = CASE WHEN lower(valid_at) = '2018-01-01' THEN 
datemultirange(daterange('2018-01-01', '2018-01-05'))
                        WHEN lower(valid_at) = '2018-02-01' THEN 
datemultirange(daterange('2018-01-05', '2018-03-01')) END
    WHERE id = '[6,7)';
-ERROR:  update or delete on table "temporal_mltrng" violates RESTRICT setting of foreign key 
constraint "temporal_fk_mltrng2mltrng_fk" on table "temporal_fk_mltrng2mltrng"
-DETAIL:  Key (id, valid_at)=([6,7), {[2018-01-01,2018-02-01)}) is referenced from table 
"temporal_fk_mltrng2mltrng".
  -- a PK update that fails because both are referenced (even before commit):
  BEGIN;
    ALTER TABLE temporal_fk_mltrng2mltrng
```

So that is relieving. Still it's interesting that it's a 6:1 ratio.

I've attached a patch that causes both failures to appear every time (v48.0). It shows that if the 
RESTRICT constraint accidentally loaded the cached query plan from the most recently cached NO 
ACTION constraint (which we test just before testing RESTRICT), it would create matching failures. 
So some kind of oid conflict could cause that.

On 1/27/25 07:56, Peter Eisentraut wrote:
 > I think this call in ri_restrict()
 >
 >      ri_BuildQueryKey(&qkey, riinfo, RI_PLAN_RESTRICT);
 >
 > needs to use a different third argument for NO ACTION vs. RESTRICT, since we are now sometimes using
 > different queries for them.
 >
 > However, the RI_QueryKey also uses the constraint OID as part of the hash key, so even this mistake
 > would not trigger any bad effect unless we also have OID collisions?

That is my take too. I haven't worked out how an OID collision could happen though. Since we are 
running the tests in parallel could the other tests generate enough oids to roll the counter around? 
Surely not. And I confirmed the dynahash does a memcmp on the whole 64 bits of key->constr_id + 
key->constr_queryno. Landing in the same hash bucket shouldn't be a problem (though I haven't tested 
that, e.g. by using a debugger to manipulate the hash result). So I don't have anything plausible here.

I thought about introducing a new RI_PLAN_NO_ACTION constant back when I wrote the patch. It 
shouldn't be needed, but it would be reassuring to include it, especially since the generated SQL 
changes on NO ACTION vs RESTRICT. (On the other hand the generated SQL also depends on the PK/FK 
attributes and their comparison operators, and we don't include *those* in the cache key.)

Is it possible to commit an RI_PLAN_NO_ACTION addition and see if that makes the buildfarm failures 
go away? Here is a proposed patch for that (v48.1). I would understand if this is too questionable a 
practice---but it would be nice to get sufficient test exposure to see if it makes a difference. 
Since I still haven't reproduced this locally (despite running continuously for almost a week), it's 
not an experiment I can do myself. If it *does* make the failures go away, then it suggests there is 
still some latent problem somewhere.

I took a look through the dynahash code as well as GetNewOidWithIndex/GetNewObjectId. Neither of 
these really seem like likely places to find a bug to me, considering how mature and heavily-used 
they are. The hash table isn't even shared between backends. The way we keep a nextOid in shared 
memory and keep incrementing it until we find a gap is maybe interesting. Since we drop & create a 
constraint right before the failing test, I guess it's possible to cycle around and get the same oid 
as the dropped constraint. I don't really buy it though. We would have to give the NO ACTION 
constraint a very low oid (so there aren't lower-numbered gaps produced by the same test file), drop 
it, somehow consume 2^32 oids (in the other tests from the parallel group), and then land back on 
the low-numbered open oid. Also from the failure I checked I don't see any log messages about "new 
OID has been assigned in relation ... after ... retries". I guess you could hit the right oid 
without that, but it seems hard.

That's it so far. Adding v48.1 would at least give us some more evidence about where to look for 
problems. In the meantime I'll keep searching for a way to reproduce it!

[1] https://cirrus-ci.com/task/5985049025183744 -> 
https://api.cirrus-ci.com/v1/artifact/task/5985049025183744/log/src/bin/pg_upgrade/tmp_check/regression.diffs

Yours,

-- 
Paul              ~{:-)
pj@illuminatedcomputing.com

--------------9LU7uB059OesdM0j2LCf0l8c
Content-Type: text/plain; charset=UTF-8;
 name="v48.0-0001-Trigger-the-RESTRICT-build-farm-failures-consis.patch.nocfbot"
Content-Disposition: attachment;
 filename*0="v48.0-0001-Trigger-the-RESTRICT-build-farm-failures-consis.p";
 filename*1="atch.nocfbot"
Content-Transfer-Encoding: base64

RnJvbSBiOGMzYmZiODYxNzA2NmM5MjRmN2I3NGY3Y2M1ZTZhZDA4Y2Q0MjYxIE1vbiBTZXAg
MTcgMDA6MDA6MDAgMjAwMQpGcm9tOiAiUGF1bCBBLiBKdW5nd2lydGgiIDxwakBpbGx1bWlu
YXRlZGNvbXB1dGluZy5jb20+CkRhdGU6IFR1ZSwgMjggSmFuIDIwMjUgMjA6MTE6MzEgLTA4
MDAKU3ViamVjdDogW1BBVENIIHYwXSBUcmlnZ2VyIHRoZSBSRVNUUklDVCBidWlsZCBmYXJt
IGZhaWx1cmVzIGNvbnNpc3RlbnRseQoKLS0tCiBzcmMvYmFja2VuZC91dGlscy9hZHQvcmlf
dHJpZ2dlcnMuYyB8IDUgKysrKysKIDEgZmlsZSBjaGFuZ2VkLCA1IGluc2VydGlvbnMoKykK
CmRpZmYgLS1naXQgYS9zcmMvYmFja2VuZC91dGlscy9hZHQvcmlfdHJpZ2dlcnMuYyBiL3Ny
Yy9iYWNrZW5kL3V0aWxzL2FkdC9yaV90cmlnZ2Vycy5jCmluZGV4IDNkOTk4NWIxN2MyLi44
ZWJkYWZjOTkxMyAxMDA2NDQKLS0tIGEvc3JjL2JhY2tlbmQvdXRpbHMvYWR0L3JpX3RyaWdn
ZXJzLmMKKysrIGIvc3JjL2JhY2tlbmQvdXRpbHMvYWR0L3JpX3RyaWdnZXJzLmMKQEAgLTcw
MSw2ICs3MDEsOCBAQCBSSV9GS2V5X3Jlc3RyaWN0X3VwZChQR19GVU5DVElPTl9BUkdTKQog
CXJldHVybiByaV9yZXN0cmljdCgoVHJpZ2dlckRhdGEgKikgZmNpbmZvLT5jb250ZXh0LCBm
YWxzZSk7CiB9CiAKK3N0YXRpYyBPaWQgbGFzdENhY2hlZENvbnN0cmFpbnQgPSBJbnZhbGlk
T2lkOworCiAvKgogICogcmlfcmVzdHJpY3QgLQogICoKQEAgLTc1Myw2ICs3NTUsOCBAQCBy
aV9yZXN0cmljdChUcmlnZ2VyRGF0YSAqdHJpZ2RhdGEsIGJvb2wgaXNfbm9fYWN0aW9uKQog
CSAqIHF1ZXJ5IGZvciBkZWxldGUgYW5kIHVwZGF0ZSBjYXNlcykKIAkgKi8KIAlyaV9CdWls
ZFF1ZXJ5S2V5KCZxa2V5LCByaWluZm8sIFJJX1BMQU5fUkVTVFJJQ1QpOworCWlmICghaXNf
bm9fYWN0aW9uKQorCQlxa2V5LmNvbnN0cl9pZCA9IGxhc3RDYWNoZWRDb25zdHJhaW50Owog
CiAJaWYgKChxcGxhbiA9IHJpX0ZldGNoUHJlcGFyZWRQbGFuKCZxa2V5KSkgPT0gTlVMTCkK
IAl7CkBAIC04ODQsNiArODg4LDcgQEAgcmlfcmVzdHJpY3QoVHJpZ2dlckRhdGEgKnRyaWdk
YXRhLCBib29sIGlzX25vX2FjdGlvbikKIAkJLyogUHJlcGFyZSBhbmQgc2F2ZSB0aGUgcGxh
biAqLwogCQlxcGxhbiA9IHJpX1BsYW5DaGVjayhxdWVyeWJ1Zi5kYXRhLCByaWluZm8tPm5r
ZXlzLCBxdWVyeW9pZHMsCiAJCQkJCQkJICZxa2V5LCBma19yZWwsIHBrX3JlbCk7CisJCWxh
c3RDYWNoZWRDb25zdHJhaW50ID0gcmlpbmZvLT5jb25zdHJhaW50X2lkOwogCX0KIAogCS8q
Ci0tIAoyLjQyLjAKCg==
--------------9LU7uB059OesdM0j2LCf0l8c
Content-Type: text/x-patch; charset=UTF-8;
 name="v48.1-0001-Cache-NO-ACTION-foreign-keys-separately-from-R.patch"
Content-Disposition: attachment;
 filename*0="v48.1-0001-Cache-NO-ACTION-foreign-keys-separately-from-R.pa";
 filename*1="tch"
Content-Transfer-Encoding: base64

RnJvbSBjZGFhODZjOTZhZDBlZGU0N2M2ZWEwMWQ2YTk2MTA5MDc0MWQ3ZmJmIE1vbiBTZXAg
MTcgMDA6MDA6MDAgMjAwMQpGcm9tOiAiUGF1bCBBLiBKdW5nd2lydGgiIDxwakBpbGx1bWlu
YXRlZGNvbXB1dGluZy5jb20+CkRhdGU6IFR1ZSwgMjggSmFuIDIwMjUgMjA6MjM6MjIgLTA4
MDAKU3ViamVjdDogW1BBVENIIHY0OC4xXSBDYWNoZSBOTyBBQ1RJT04gZm9yZWlnbiBrZXlz
IHNlcGFyYXRlbHkgZnJvbSBSRVNUUklDVAogZm9yZWlnbiBrZXlzCgpOb3cgdGhhdCB3ZSBn
ZW5lcmF0ZSBkaWZmZXJlbnQgU1FMIGZvciB0ZW1wb3JhbCBOTyBBQ1RJT04gdnMgUkVTVFJJ
Q1QKZm9yZWlnbiBrZXlzLCB3ZSBzaG91bGQgY2FjaGUgdGhlaXIgcXVlcnkgcGxhbnMgd2l0
aCBkaWZmZXJlbnQga2V5cy4KU2luY2UgdGhlIGtleSBhbHNvIGluY2x1ZGVzIHRoZSBjb25z
dHJhaW50IG9pZCwgdGhpcyBzaG91bGRuJ3QgYmUKbmVjZXNzYXJ5LCBidXQgd2UgaGF2ZSBi
ZWVuIHNlZWluZyBidWlsZCBmYXJtIGZhaWx1cmVzIHRoYXQgc3VnZ2VzdCB3ZQptaWdodCBi
ZSBzb21ldGltZXMgdXNpbmcgYSBjYWNoZWQgTk8gQUNUSU9OIHBsYW4gdG8gaW1wbGVtZW50
IGEgUkVTVFJJQ1QKY29uc3RyYWludC4KLS0tCiBzcmMvYmFja2VuZC91dGlscy9hZHQvcmlf
dHJpZ2dlcnMuYyB8IDEzICsrKysrKystLS0tLS0KIDEgZmlsZSBjaGFuZ2VkLCA3IGluc2Vy
dGlvbnMoKyksIDYgZGVsZXRpb25zKC0pCgpkaWZmIC0tZ2l0IGEvc3JjL2JhY2tlbmQvdXRp
bHMvYWR0L3JpX3RyaWdnZXJzLmMgYi9zcmMvYmFja2VuZC91dGlscy9hZHQvcmlfdHJpZ2dl
cnMuYwppbmRleCAzZDk5ODViMTdjMi4uODQ3MzQ0ODg0OWMgMTAwNjQ0Ci0tLSBhL3NyYy9i
YWNrZW5kL3V0aWxzL2FkdC9yaV90cmlnZ2Vycy5jCisrKyBiL3NyYy9iYWNrZW5kL3V0aWxz
L2FkdC9yaV90cmlnZ2Vycy5jCkBAIC03NCwxMiArNzQsMTMgQEAKIC8qIHRoZXNlIHF1ZXJp
ZXMgYXJlIGV4ZWN1dGVkIGFnYWluc3QgdGhlIEZLIChyZWZlcmVuY2luZykgdGFibGU6ICov
CiAjZGVmaW5lIFJJX1BMQU5fQ0FTQ0FERV9PTkRFTEVURQkJMwogI2RlZmluZSBSSV9QTEFO
X0NBU0NBREVfT05VUERBVEUJCTQKKyNkZWZpbmUgUklfUExBTl9OT19BQ1RJT04JCQkJNQog
LyogRm9yIFJFU1RSSUNULCB0aGUgc2FtZSBwbGFuIGNhbiBiZSB1c2VkIGZvciBib3RoIE9O
IERFTEVURSBhbmQgT04gVVBEQVRFIHRyaWdnZXJzLiAqLwotI2RlZmluZSBSSV9QTEFOX1JF
U1RSSUNUCQkJCTUKLSNkZWZpbmUgUklfUExBTl9TRVROVUxMX09OREVMRVRFCQk2Ci0jZGVm
aW5lIFJJX1BMQU5fU0VUTlVMTF9PTlVQREFURQkJNwotI2RlZmluZSBSSV9QTEFOX1NFVERF
RkFVTFRfT05ERUxFVEUJCTgKLSNkZWZpbmUgUklfUExBTl9TRVRERUZBVUxUX09OVVBEQVRF
CQk5CisjZGVmaW5lIFJJX1BMQU5fUkVTVFJJQ1QJCQkJNgorI2RlZmluZSBSSV9QTEFOX1NF
VE5VTExfT05ERUxFVEUJCTcKKyNkZWZpbmUgUklfUExBTl9TRVROVUxMX09OVVBEQVRFCQk4
CisjZGVmaW5lIFJJX1BMQU5fU0VUREVGQVVMVF9PTkRFTEVURQkJOQorI2RlZmluZSBSSV9Q
TEFOX1NFVERFRkFVTFRfT05VUERBVEUJCTEwCiAKICNkZWZpbmUgTUFYX1FVT1RFRF9OQU1F
X0xFTiAgKE5BTUVEQVRBTEVOKjIrMykKICNkZWZpbmUgTUFYX1FVT1RFRF9SRUxfTkFNRV9M
RU4gIChNQVhfUVVPVEVEX05BTUVfTEVOKjIpCkBAIC03NTIsNyArNzUzLDcgQEAgcmlfcmVz
dHJpY3QoVHJpZ2dlckRhdGEgKnRyaWdkYXRhLCBib29sIGlzX25vX2FjdGlvbikKIAkgKiBG
ZXRjaCBvciBwcmVwYXJlIGEgc2F2ZWQgcGxhbiBmb3IgdGhlIHJlc3RyaWN0IGxvb2t1cCAo
aXQncyB0aGUgc2FtZQogCSAqIHF1ZXJ5IGZvciBkZWxldGUgYW5kIHVwZGF0ZSBjYXNlcykK
IAkgKi8KLQlyaV9CdWlsZFF1ZXJ5S2V5KCZxa2V5LCByaWluZm8sIFJJX1BMQU5fUkVTVFJJ
Q1QpOworCXJpX0J1aWxkUXVlcnlLZXkoJnFrZXksIHJpaW5mbywgaXNfbm9fYWN0aW9uID8g
UklfUExBTl9OT19BQ1RJT04gOiBSSV9QTEFOX1JFU1RSSUNUKTsKIAogCWlmICgocXBsYW4g
PSByaV9GZXRjaFByZXBhcmVkUGxhbigmcWtleSkpID09IE5VTEwpCiAJewotLSAKMi40Mi4w
Cgo=

--------------9LU7uB059OesdM0j2LCf0l8c--