Contents
- How to fix flaky tests
- ignore timing statistics for VACUUM VERBOSE
- ignore timing statistics for VACUUM VERBOSE
How to fix flaky tests
Flaky tests happen when for some reason our tests return non-deterministic results.
There are three different causes of flaky tests: 1. Tests that don't make sure output is consistent, i.e. a bug in our tests 2. Bugs in our testing infrastructure 3. Bugs in Citus itself
All of these impact the happiness and productivity of our developers, because we have to rerun tests to make them pass. But apart from developer happiness and productivity, 3 also impacts our users, and by ignoring flaky tests we can miss problems that our users could run into. This reduces the effectiveness of our tests.
Reproducing a flaky test
1. Reproduce a flaky test in CI
Before trying to fix the flakyness, it's important that you can reproduce the
flaky test. Often it only reproduces in CI, so we have a CI job that can help
you reproduce flakyness consistently by running the same test a lot of times.
You can configure CI to run this job by setting the flaky_test
diff
flaky_test:
type: string
- default: ''
+ default: 'isolation_shard_rebalancer_progress'
Once you get this job to consistently fail in CI, you can continue with the next steps to make it instead consistently pass. If the failure doesn't reproduce with this CI job, it's almost certainly caused by running it concurrently with other tests. See the "Don't run test in parallel with others" section below on how to fix that.
2. Reproduce a flaky test in local environment
To reproduce the flaky tests on your local environment, you can use run-test.py [test_name]
script like below.
bash
src/test/regress/citus_tests/run_test.py isolation_shard_rebalancer_progress -r 1000 --use-base-schedule --use-whole-schedule-line
The script above will try to run the whole line in the schedule file containing the test name by using the related base_schedule (rather than a minimal_schedule), 1000 times.
Easy fixes
The following types of issues all fall within the category 1: bugs in our tests.
Expected records but different order
Issue: A query returns the right result, but they are in a different order than expected by the output.
Fix: Add an extra column to the ORDER BY clause of the query to make the output consistent
Example
diff
8970008 | colocated_dist_table | -2147483648 | 2147483647 | localhost | 57637
8970009 | colocated_partitioned_table | -2147483648 | 2147483647 | localhost | 57637
8970010 | colocated_partitioned_table_2020_01_01 | -2147483648 | 2147483647 | localhost | 57637
- 8970011 | reference_table | | | localhost | 57637
8970011 | reference_table | | | localhost | 57638
+ 8970011 | reference_table | | | localhost | 57637
(13 rows)
Example fix:
diff
-ORDER BY logicalrelid, shardminvalue::BIGINT;
+ORDER BY logicalrelid, shardminvalue::BIGINT, nodeport;
Expected logs but different order
Issue: The logs in the regress output are displayed in a different order than what the output file shows
Fix: It's simple: don't log these things during the test. There are two common
ways of achieving this:
1. If you don't care about the logs for this query at all, then you can change
the log VERBOSITY
or lower client_min_messages
.
2. If these are logs of uninteresting commands created by
citus.log_remote_commands
, but you care about some of the other remote
commands being as expected, then you can use citus.grep_remote_commands
to
only display the commands that you care about.
Example of issue 1: ```diff select alter_table_set_access_method('ref','heap'); NOTICE: creating a new table for alter_table_set_access_method.ref NOTICE: moving the data of alter_table_set_access_method.ref NOTICE: dropping the old alter_table_set_access_method.ref NOTICE: drop cascades to 2 other objects -DETAIL: drop cascades to materialized view m_ref -drop cascades to view v_ref +DETAIL: drop cascades to view v_ref +drop cascades to materialized view m_ref CONTEXT: SQL statement "DROP TABLE alter_table_set_access_method.ref CASCADE" NOTICE: renaming the new table to alter_table_set_access_method.ref alter_table_set_access_method
(1 row) ```
Example fix of issue 1
diff
+\set VERBOSITY terse
Example of issue 2
diff
SET citus.log_remote_commands TO ON;
-- should propagate to all workers because no table is specified
ANALYZE;
NOTICE: issuing BEGIN TRANSACTION ISOLATION LEVEL READ COMMITTED;SELECT assign_distributed_transaction_id(0, 3461, '2022-08-19 01:56:06.35816-07');
DETAIL: on server postgres@localhost:57637 connectionId: 1
NOTICE: issuing BEGIN TRANSACTION ISOLATION LEVEL READ COMMITTED;SELECT assign_distributed_transaction_id(0, 3461, '2022-08-19 01:56:06.35816-07');
DETAIL: on server postgres@localhost:57638 connectionId: 2
NOTICE: issuing SET citus.enable_ddl_propagation TO 'off'
DETAIL: on server postgres@localhost:57637 connectionId: 1
-NOTICE: issuing SET citus.enable_ddl_propagation TO 'off'
-DETAIL: on server postgres@localhost:xxxxx connectionId: xxxxxxx
NOTICE: issuing ANALYZE
DETAIL: on server postgres@localhost:57637 connectionId: 1
+NOTICE: issuing SET citus.enable_ddl_propagation TO 'off'
+DETAIL: on server postgres@localhost:57638 connectionId: 2
NOTICE: issuing ANALYZE
DETAIL: on server postgres@localhost:57638 connectionId: 2
Example fix of issue 2
diff
SET citus.log_remote_commands TO ON;
+SET citus.grep_remote_commands = '%ANALYZE%';
Isolation test completes in different order
Issue: There's no defined order in which the steps in two different sessions complete, because they don't block each other. This can happen when two sessions were both blocked by a third session, but when the third session releases the lock the first two can both continue.
Fix: Use the isolation test "marker" feature to make sure one step can only complete after another has completed.
Example ```diff -step s1-shard-move-c1-block-writes: <... completed> +step s4-shard-move-sep-block-writes: <... completed> citus_move_shard_placement
(1 row)
-step s4-shard-move-sep-block-writes: <... completed> +step s1-shard-move-c1-block-writes: <... completed> citus_move_shard_placement
```
Example fix
diff
+permutation ... "s1-shard-move-c1-block-writes" "s4-shard-move-sep-block-writes" ...
+permutation ... "s1-shard-move-c1-block-writes" "s4-shard-move-sep-block-writes"("s1-shard-move-c1-block-writes") ...
Disk size numbers are not exactly like expected
Issue: In some tests we show the disk size of a table, but due to various postgres background processes such as vacuuming these sizes can change slightly.
Fix: Expect a certain range of disk sizes instead of a specific one.
Example ```diff VACUUM (INDEX_CLEANUP ON, PARALLEL 1) local_vacuum_table; SELECT pg_size_pretty( pg_total_relation_size('local_vacuum_table') ); pg_size_pretty
- 21 MB
- 22 MB (1 row) ```
Example fix ```diff -SELECT pg_size_pretty( pg_total_relation_size('local_vacuum_table') ); - pg_size_pretty +SELECT CASE WHEN s BETWEEN 20000000 AND 25000000 THEN 22500000 ELSE s END +FROM pg_total_relation_size('local_vacuum_table') s ; + s
- 21 MB
- 22500000 ```
Isolation test flakyness
If the flaky test is an isolation test, first read the Postgres docs on dealing with race conditions in isolation tests. A common example was already listed above, but the Postgres docs list some other types too and explain how to make their output consistent.
Ruling out common sources of randomness as the cause
If it's none of the above, then probably the reason why the test is flaky is not immediately obvious. There are a few things that can introduce randomness into our test suite. To keep your sanity while investigating, it's good to rule these out as the cause (or even better determine that they are the cause).
Don't run test in parallel with others
Check in the schedule if the test is run in parallel with others. If it is, remove it from there and check if it's still flaky.
Example
diff
test: multi_partitioning_utils replicated_partitioned_table
-test: multi_partitioning partitioning_issue_3970
+test: multi_partitioning
+test: partitioning_issue_3970
test: drop_partitioned_table
Use a fixed number of connections
The adaptive executor of Citus sometimes opens extra connections to do stuff in parallel to speed up multi-shard queries. This happens especially in CI, because CI machines are sometimes slow. There are two ways to get a consistent number of connections:
- Use
citus.max_adaptive_executor_pool_size
to limit the connections - Use
citus.force_max_query_parallelization
to always open the maximum number of connections.
Example
diff
ALTER TABLE dist_partitioned_table ADD CONSTRAINT constraint1 UNIQUE (dist_col, partition_col);
+ERROR: canceling the transaction since it was involved in a distributed deadlock
Example of fix 1
diff
+SET citus.max_adaptive_executor_pool_size TO 1;
ALTER TABLE dist_partitioned_table ADD CONSTRAINT constraint1 UNIQUE (dist_col, partition_col);
+RESET citus.max_adaptive_executor_pool_size;
Example of fix 2
diff
+SET citus.force_max_query_parallelization TO 1;
ALTER TABLE dist_partitioned_table ADD CONSTRAINT constraint1 UNIQUE (dist_col, partition_col);
+RESET citus.force_max_query_parallelization;
IMPORTANT: If this helps, this could very well indicate a bug. Check with senior/principal engineers if it's expected that it helps in this case.
What to do if this all doesn't work?
If none of the advice above worked, the first thing to try is read the failing test in detail and try to understand how it works. Often, with a bit of thinking you can figure out why it's failing in the way that it's failing. If you cannot figure it out yourself, it's good to ask senior/principal engineers, maybe they can think of the reason. Or maybe they're certain that it's an actual bug.
What to do when you cannot fix or find the bug?
If it turns out to be an actual bug in Citus, but fixing the bug (or finding its cause) is hard, making the test output consistent is already an improvement over the status quo. Be sure to create an issue though for the bug. Even if you're not entirely sure what's causing it you can still create an issue describing how to reproduce the flakiness.
What to do if output can never be consistent?
There are still a few ways to make our test suite less flaky, even if you figured out that the output that Postgres gives can never be made consistent.
Normalizing random output
If for some reason you cannot make consistent output then our
normalize.sed
might come to the rescue. This allows us to
normalize certain lines to one specific output.
Example
diff
-CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s.
+CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.02 s.
Fix by changing inconsistent parts of line ```sed
ignore timing statistics for VACUUM VERBOSE
s/CPU: user: .s, system: .s, elapsed: .*s/CPU: user: X.XX s, system: X.XX s, elapsed: X.XX s/ ```
Fix by completely removing line ```sed
ignore timing statistics for VACUUM VERBOSE
/CPU: user: .s, system: .s, elapsed: .*s/d ```
Removing the flaky test
Sometimes removing the test is the only way to make our test suite less flaky. Of course this is a last resort, but sometimes it's what we want. If running the test does more bad than good, removing will be a net positive.
PR descriptions of flaky tests
Even if a fix for a flaky test is very simple without a clear description it can be hard for a reviewer (or a future git spelunker) to understand its purpose. A good PR description of a flaky test includes the following things: 1. Name of the test that was flaky 2. The part of the regression.diffs file that caused the test to fail randomly 3. A link to a CI run that failed because of this flaky test 4. Explanation of why this output was non-deterministic (was it a bug in Citus?) 5. Explanation of how this change makes the test deterministic
An example of such a PR description is this one from #6272:
Sometimes in CI our multi_utilities test fails like this: ```diff VACUUM (INDEX_CLEANUP ON, PARALLEL 1) local_vacuum_table; SELECT CASE WHEN s BETWEEN 20000000 AND 25000000 THEN 22500000 ELSE s END size FROM pg_total_relation_size('local_vacuum_table') s ; size
- 22500000
- 39518208 (1 row) ``` Source: https://app.circleci.com/pipelines/github/citusdata/citus/26641/workflows/5caea99c-9f58-4baa-839a-805aea714628/jobs/762870
Apparently VACUUM is not as reliable in cleaning up as we thought. This PR increases the range of allowed values to make the test reliable. Important to note is that the range is still completely outside of the allowed range of the initial size. So we know for sure that some data was cleaned up.