Failures in test_nbtree_pagesplit_cycleid

[jcsp]

https://neonprod.grafana.net/d/fddp4rvg7k2dcf/regression-test-failures?orgId=1&var-test_name=test_nbtree_pagesplit_cycleid&from=now-7d&to=now&timezone=utc&var-restrict=true&var-max_count=100&var-reference=$__all&var-ignore_reference=refs%2Fpull%2F0000%2Fmerge

[MMeent]

The biggest source of flakyness of the test has been reduced significantly since #10413, with remaining flakyness (1 failure every few days) not quite fully understood.

[alexanderlaw]

I've come across a failure of this test when testing a sans-enabled build on ARM:
https://neon-github-public-dev.s3.amazonaws.com/reports/branch-enable-sanitizers-for-v17/12862934608/index.html#/testresult/33599e40bfabe4ea

test_runner/regress/test_nbtree_pagesplit_cycleid.py:122: in test_nbtree_pagesplit_cycleid
    assert (
E   AssertionError: 3 page splits with cycle ID expected; actual [(2, 'cd03')]
E   assert (1 == 1 and 2 == 3)
E    +  where 1 = len([(2, 'cd03')])

and then reproduced it locally, on x86_64, when running 8 test instances (also with sanitizers) in parallel, on iteration 1. And I can reproduce it even with sleep(2) -> sleep(10). Will try to investigate this.

[alexanderlaw]

By the way, I wonder whether [1, pg_relation_size('t_uidx'::regclass) / 8192] here is a correct range for block numbers?

neon/test_runner/regress/test_nbtree_pagesplit_cycleid.py

Line 18 in 2ab9f69

FROM generate_series(1, pg_relation_size('t_uidx'::regclass) / 8192) AS blkno,

Doesn't get_raw_page_at_lsn() return blocks numbered from 0?

As far as I can see, get_raw_page_at_lsn() doesn't check blocknum validity (e.g. it works for blocknum = 100000 or blocknum = -1), but when requesting block 10 from the t_uidx relation, I get a zero-only page, while page 0 returned contains some data.

[knizhnik]

By the way, I wonder whether [1, pg_relation_size('t_uidx'::regclass) / 8192] here is a correct range for block numbers?
Page 0 is index header.

[alexanderlaw]

Page 0 is index header.

Yes, I understand, my question was mostly about blocknum passed to get_raw_page_at_lsn(): is it 0- or 1-based...

[knizhnik]

This test checks btpo_cycleid which is part of nbtree page opaque structure. It is available at all nitre pages except header.

[alexanderlaw]

Still trying to find out what makes the test fail, but I see the following difference with the modified query:

...
    SELECT blkno,
           encode(cycle_id, 'hex')
     FROM parsed_pages
    WHERE encode(cycle_id, 'hex') != '0000';

[(1, '4d6a'), (7, '4d6a'), (8, '4d6a')]
(when the test passes)
vs

 blkno | encode 
-------+--------
     8 | 6b6f
     9 | 6b6f

when it fails.

I've also added

@@ -1517,6 +1517,7 @@ _bt_split(Relation rel, Relation heaprel, BTScanInsert itup_key, Buffer buf,
     origpagenumber = BufferGetBlockNumber(buf);
     /* NEON: store the page's former cycle ID for FPI check later */
     origcycleid = oopaque->btpo_cycleid;
+elog(LOG, "!!!_bt_split| origpagenumber: %d", origpagenumber);

for debugging and seeing the following:

PG:2025-01-21 09:35:25.224 GMT [postgres][470331:1730][client backend] [[unknown]] LOG:  !!!_bt_split| origpagenumber: 1
PG:2025-01-21 09:35:25.229 GMT [postgres][470331:2839][client backend] [[unknown]] LOG:  !!!_bt_split| origpagenumber: 2
PG:2025-01-21 09:35:25.233 GMT [postgres][470331:3946][client backend] [[unknown]] LOG:  !!!_bt_split| origpagenumber: 4
PG:2025-01-21 09:35:25.237 GMT [postgres][470331:5053][client backend] [[unknown]] LOG:  !!!_bt_split| origpagenumber: 5
PG:2025-01-21 09:35:25.241 GMT [postgres][470331:6160][client backend] [[unknown]] LOG:  !!!_bt_split| origpagenumber: 6
PG:2025-01-21 09:35:35.533 GMT [postgres][470331:8170][client backend] [[unknown]] LOG:  !!!_bt_split| origpagenumber: 7
PG:2025-01-21 09:35:35.537 GMT [postgres][470331:9272][client backend] [[unknown]] LOG:  !!!_bt_split| origpagenumber: 1

(when the test passes)

PG:2025-01-21 09:56:58.464 GMT [postgres][501164:1760][client backend] [[unknown]] LOG:  !!!_bt_split| origpagenumber: 1
PG:2025-01-21 09:56:58.471 GMT [postgres][501164:2869][client backend] [[unknown]] LOG:  !!!_bt_split| origpagenumber: 2
PG:2025-01-21 09:56:58.478 GMT [postgres][501164:3976][client backend] [[unknown]] LOG:  !!!_bt_split| origpagenumber: 4
PG:2025-01-21 09:56:58.482 GMT [postgres][501164:5083][client backend] [[unknown]] LOG:  !!!_bt_split| origpagenumber: 5
PG:2025-01-21 09:56:58.489 GMT [postgres][501164:6190][client backend] [[unknown]] LOG:  !!!_bt_split| origpagenumber: 6
PG:2025-01-21 09:57:08.870 GMT [postgres][501164:8181][client backend] [[unknown]] LOG:  !!!_bt_split| origpagenumber: 7
PG:2025-01-21 09:57:08.874 GMT [postgres][501164:9284][client backend] [[unknown]] LOG:  !!!_bt_split| origpagenumber: 8

(when the test fails)

So maybe the index can be split in several ways?

[ololobus]

@MMeent will check the remaining failures later this week