[Bug] Regression reindextable_while_reindex_idx_ao_part_btree failed occasionally

Cloudberry Database version

last commit in #19

What happened

Flaky tests:

https://github.com/cloudberrydb/cloudberrydb/actions/runs/5597543818/jobs/10236557444

/code/gpdb_src/src/test/isolation2/results/reindex/reindextable_while_reindex_idx_ao_part_btree.out	2023-07-19 11:24:41.248927590 +0000
@@ -40,9 +40,9 @@
 3: select distinct count(distinct relfilenode), relname from old_relfilenodes group by dbid, relname;
  count | relname                                           
 -------+---------------------------------------------------
- 1     | reindex_crtab_part_ao_btree_1_prt_p_one_id_idx    
  1     | reindex_crtab_part_ao_btree_id_idx                
  2     | reindex_crtab_part_ao_btree_1_prt_de_fault_id_idx 
+ 2     | reindex_crtab_part_ao_btree_1_prt_p_one_id_idx    
 (3 rows)
 3: COMMIT;
 COMMIT
@@ -57,8 +57,8 @@
  count | relname                                           
 -------+---------------------------------------------------
  1     | reindex_crtab_part_ao_btree_id_idx                
+ 2     | reindex_crtab_part_ao_btree_1_prt_de_fault_id_idx 
  2     | reindex_crtab_part_ao_btree_1_prt_p_one_id_idx    
- 3     | reindex_crtab_part_ao_btree_1_prt_de_fault_id_idx 
 (3 rows)

What you think should happen instead

No response

How to reproduce

[icw-orca-test]

ORCA planner run regression reindextable_while_reindex_idx_ao_part_btree

Operating System

CI [icw-orca-test]'s OS

Anything else

The regression is under ORCA, it seems has nothing to do with parallel, I guess.
Until this commit, GUC gp_appendonly_insert_files is not enabled with enable_parallel is false. So, it should has nothing with that too.
Any reindex is a writeable operation, can't be parallel in principle.
I saw this regression failed several times at Gitlab last month.

Are you willing to submit PR?

Yes, I am willing to submit a PR!

Code of Conduct

I agree to follow this project's Code of Conduct.

@avamingli

Hey, @avamingli welcome!🎊 Thanks for taking the time to point this out.🙌

initial findings:

This bug is a lot more easier to reproduce under high load.
When running it in a stress-free environment (load average 2.5/8), the bug occurs in 1 out of 200 tries. But when I use a
stress -u 6 to simulate resource-critical situation (load average 6.5/8) the bug occurs in under 5 times (at most 13 times) of tries.
Seems this bug can also be replicated w/o Orca enabled.
I use export PGOPTIONS='-c optimizer=off'; and psql -c 'explain select version();' to verify the setting is working before executing the test command to turn Orca off. The bug still shows.
Seems this bug is irrelevant to gp_appendonly_insert_files.
gpconfig -s gp_appendonly_insert_files returns 4 as default value. and icw actually set it to 0 before run the test. I manually test the two situations, the bug occurred in both of them.

scripts to reproduce the bug:

rm regression.diffs regression.out;
rm -f gpdiff.pl && ln -s ../../../src/test/regress/gpdiff.pl;
gpstop -u;
export PGOPTIONS='-c optimizer=on';
# export PGOPTIONS='-c optimizer=off';
psql -c 'explain select version();' postgres
../../../src/test/regress/scan_flaky_fault_injectors.sh && ../../../src/test/isolation2/pg_isolation2_regress --inputdir=. --bindir='/home/gpadmin/install/cbdb/bin'    --load-extension=gp_inject_fault --init-file=../../../src/test/regress/init_file --init-file=./init_file_isolation2 $1;

import argparse
import subprocess
from rich.console import Console
from rich.progress import track

if __name__ == '__main__':
    console = Console()
    parser = argparse.ArgumentParser(prog="regress.py", description="Run specified tests or schedules multiple times")
    # parser.add_argument("--schedule", action="extend", nargs="+")
    parser.add_argument("--test", action="extend", nargs="+")
    parser.add_argument("-n")
    args = parser.parse_args()

    test = args.test
    n = int(args.n)
    assert (len(test) > 0)
    with open("regress.py.out", "w") as f:
        for i in track(range(n), description="Processing...", show_speed=False):
            subprocess.run(['bash', './regress.sh', *test], check=True, stdout=f, stderr=f)

This bug is a lot more easier to reproduce under high load.
When running it in a stress-free environment (load average 2.5/8), the bug occurs in 1 out of 200 tries. But when I use a
stress -u 6 to simulate resource-critical situation (load average 6.5/8) the bug occurs in under 5 times (at most 13 times) of tries.

Nice. Reproduce is a good start.

Seems this bug is irrelevant to gp_appendonly_insert_files.
gpconfig -s gp_appendonly_insert_files returns 4 as default value. and icw actually set it to 0 before run the test. I manually test the two situations, the bug occurred in both of them.

Yeah, it should has nothing to do with that GUC. I prefer to take a look at reindex concurrently related codes.

I just found that GPDB has the same bug as well. This bug is from the upstream.

$ cat regression.diffs
diff -I HINT: -I CONTEXT: -I GP_IGNORE: -U3 /home/gpadmin/gpdb/src/test/isolation2/expected/reindex/reindextable_while_reindex_idx_ao_part_btree.out /home/gpadmin/gpdb/src/test/isolation2/results/reindex/reindextable_while_reindex_idx_ao_part_btree.out
--- /home/gpadmin/gpdb/src/test/isolation2/expected/reindex/reindextable_while_reindex_idx_ao_part_btree.out       2023-08-04 17:50:34.304671451 +0800
+++ /home/gpadmin/gpdb/src/test/isolation2/results/reindex/reindextable_while_reindex_idx_ao_part_btree.out2023-08-04 17:50:34.308671578 +0800
@@ -43,7 +43,8 @@
  1     | reindex_crtab_part_ao_btree_1_prt_p_one_id_idx
  1     | reindex_crtab_part_ao_btree_id_idx
  2     | reindex_crtab_part_ao_btree_1_prt_de_fault_id_idx
-(3 rows)
+ 2     | reindex_crtab_part_ao_btree_1_prt_p_one_id_idx
+(4 rows)
 3: COMMIT;
 COMMIT
 -- After session 3 commits, session 2 could complete, the relfilenode it assigned to the
@@ -57,8 +58,8 @@
  count | relname
 -------+---------------------------------------------------
  1     | reindex_crtab_part_ao_btree_id_idx
+ 2     | reindex_crtab_part_ao_btree_1_prt_de_fault_id_idx
  2     | reindex_crtab_part_ao_btree_1_prt_p_one_id_idx
- 3     | reindex_crtab_part_ao_btree_1_prt_de_fault_id_idx
 (3 rows)

 3: select count(*) from reindex_crtab_part_ao_btree where id = 998;

$ cat regression.diffs
diff -I HINT: -I CONTEXT: -I GP_IGNORE: -U3 /home/gpadmin/gpdb/src/test/isolation2/expected/reindex/reindextable_while_reindex_idx_ao_part_btree.out /home/gpadmin/gpdb/src/test/isolation2/results/reindex/reindextable_while_reindex_idx_ao_part_btree.out
--- /home/gpadmin/gpdb/src/test/isolation2/expected/reindex/reindextable_while_reindex_idx_ao_part_btree.out       2023-08-04 18:05:14.714455706 +0800
+++ /home/gpadmin/gpdb/src/test/isolation2/results/reindex/reindextable_while_reindex_idx_ao_part_btree.out2023-08-04 18:05:14.718455760 +0800
@@ -40,9 +40,9 @@
 3: select distinct count(distinct relfilenode), relname from old_relfilenodes group by dbid, relname;
  count | relname
 -------+---------------------------------------------------
- 1     | reindex_crtab_part_ao_btree_1_prt_p_one_id_idx
  1     | reindex_crtab_part_ao_btree_id_idx
  2     | reindex_crtab_part_ao_btree_1_prt_de_fault_id_idx
+ 2     | reindex_crtab_part_ao_btree_1_prt_p_one_id_idx
 (3 rows)
 3: COMMIT;
 COMMIT
@@ -57,8 +57,8 @@
  count | relname
 -------+---------------------------------------------------
  1     | reindex_crtab_part_ao_btree_id_idx
+ 2     | reindex_crtab_part_ao_btree_1_prt_de_fault_id_idx
  2     | reindex_crtab_part_ao_btree_1_prt_p_one_id_idx
- 3     | reindex_crtab_part_ao_btree_1_prt_de_fault_id_idx
 (3 rows)

 3: select count(*) from reindex_crtab_part_ao_btree where id = 998;

I'll try to further dive into this issue from now on.

I've found that three part_btree-related tests (reindextable_while_reindex_idx_aoco_part_btree, reindextable_while_reindex_idx_ao_part_btree and reindextable_while_reindex_idx_heap_part_btree) are all problematic whereas three corresponding bitmap-related tests are all fine. Things start getting interesting... 🤔 🤔

Concluding Remarks

This issue is mainly due to the unstable nature of the three part_btree-related tests themselves. They use tx1 to lock the table exclusively, then release the lock for tx2 and tx3 to compete (at the red arrow). The tests actually assume that the txn2 get the lock before txn3, and txn2 blocked by it until txn3 completes:

When it's not the case, i.e., when txn2 get the lock and finished running in the small interval at the red arrow, the assumption no longer stands, causing the test to fail.

why snapshot and MVCC cannot prevent this

this issue is irrelevant to MVCC and snapshot. In postgres and greenplum a snapshot is not issued at the begin command, but at the first non-transaction-management statement of the txn, that's exactly when txn2 and 3 already competes for lock. So this issue is only caused by lock.

why reordering `3: begin` stmt cannot fix this

One might say that reorder begin to the beginning of the file could fix this. Unfortunately, this is not the case. Due to another bug also found in postgres and greenplum, select-s from pg_class sometimes could return intermediate result even in RR isolation level, so "fixing this issue by reordering 3: begin stmt" can actually only transform this issue to another issue, wherein due to the duplication records INSERT 16 are reported (the correct answer is INSERT 14). This is strange because although updates w.r.t. pg_class is in-place not transactional, it should directly overwrite the tuple instead of exposing a mixed, intermediate state to the user.

Any prove on this

Use @pre_run and @post_run hooks one can reliability detect whether txn2 is still blocked by txn3 when txn3 get the lock.

How to fix this

A workaround has been proposed by generally move some test work from 'ctx diff' into the SQL file itself:

apparently this is not the best way. but to stabilize the test and not introduce any alternation to the isolation2 test suite, this is the best we can do I suppose.

A PR is on the way once I packed all these into a nice write-up in the comment of the test file.

Fix unstable tests reindextable_while_reindex_idx

Refactor gp_activetable (#26)

Refactor gp_activetable (apache#26)

Add yezzey build option (apache#26)

Add yezzey build option (#26)

Navigation Menu

Repository navigation

[Bug] Regression reindextable_while_reindex_idx_ao_part_btree failed occasionally #26

Cloudberry Database version

What happened

What you think should happen instead

How to reproduce

Operating System

Anything else

Are you willing to submit PR?

Code of Conduct

Concluding Remarks

why snapshot and MVCC cannot prevent this

why reordering `3: begin` stmt cannot fix this

Any prove on this

How to fix this

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

[Bug] Regression reindextable_while_reindex_idx_ao_part_btree failed occasionally #26

Description

Cloudberry Database version

What happened

What you think should happen instead

How to reproduce

Operating System

Anything else

Are you willing to submit PR?

Code of Conduct

Activity

github-actions commented on Jul 20, 2023

Ray-Eldath commented on Aug 4, 2023

avamingli commented on Aug 4, 2023

Ray-Eldath commented on Aug 4, 2023

Ray-Eldath commented on Aug 17, 2023

Concluding Remarks

why snapshot and MVCC cannot prevent this

why reordering 3: begin stmt cannot fix this

Any prove on this

How to fix this

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions

why reordering `3: begin` stmt cannot fix this