-
Type:
Bug
-
Resolution: Unresolved
-
Priority:
Major - P3
-
None
-
Affects Version/s: None
-
Component/s: Cache and Eviction
-
Storage Engines, Storage Engines - Transactions
-
None
-
None
Here's a test that runs for around 30 seconds normally, but with the disagg hook, runs pretty consistently for over 30 minutes, apparently due to long evictions. We should understand why there's such a difference. For now, I will disable the test with a FIXME.
Here's some output - note the difference from the start timestamp to the final timestamp. Note that because of how the test is run (with pytest_parallel), all the output is collected and appears at once with the same timestamp - even though it wasn't originally produced all at the same time.
[2025/09/15 22:09:36.092] running python3 ../test/suite/run.py --noremove -v 2 --timeout 1800 --hook disagg=(role=leader,table_prefix=table) test_checkpoint_snapshot03.py
...
test_checkpoint_snapshot03.test_checkpoint_snapshot03.test_checkpoint_snapshot -s 0 (column_fix): starting
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: [pid:8779]: test_checkpoint_snapshot03.test_checkpoint_snapshot03.test_checkpoint_snapshot -s 0 (column_fix): 14.14 seconds
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: ok
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: [pid:8779]: None ... [pid:8779]: test_checkpoint_snapshot03.test_checkpoint_snapshot03.test_checkpoint_snapshot -s 1 (column): starting
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: [pid:8779]: test_checkpoint_snapshot03.test_checkpoint_snapshot03.test_checkpoint_snapshot -s 1 (column): 20.58 seconds
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: ok
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: [pid:8779]: None ... [pid:8779]: test_checkpoint_snapshot03.test_checkpoint_snapshot03.test_checkpoint_snapshot -s 2 (row_string): starting
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: [pid:8779]: Replacing, old config = "key_format=S,value_format=S,leaf_page_max=4k"
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: [pid:8779]: Replacing, new config = "key_format=S,value_format=S,leaf_page_max=4k,block_manager=disagg,type=layered"
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: [pid:8779]: ERROR: stdout.txt unexpected standard output, contains:
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: "[1757988765:571003][8779:0x7ff011eb6700], test_checkpoint_snapshot03.test_checkpoint_snapshot03.test_checkpoint_snapshot(row_string), file:test_checkpoint_snapshot03.wt_stable, eviction-server: [WT_VERB_EVICTION][WARNING]: Eviction took more than 1 minute (76611388us). Building disk image took 76590840us. History store wrapup took 5175us.
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: "
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: FAIL
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py:
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: ======================================================================
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: [pid:8779]: FAIL: None
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: ----------------------------------------------------------------------
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: [pid:8779]: Traceback (most recent call last):
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: File "/data/mci/5c814d6c7b8377bc291364fd852a223e/wiredtiger/test/suite/wttest.py", line 574, in tearDown
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: self.captureout.check(self)
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: File "/data/mci/5c814d6c7b8377bc291364fd852a223e/wiredtiger/test/suite/../py_utility/abstract_test_case.py", line 111, in check
[2025/09/15 22:35:14.734] test_checkpoint_snapshot03.py: testcase.fail('unexpected ' + self.desc + ', contains: "' +
[2025/09/15 22:35:14.735] test_checkpoint_snapshot03.py: AssertionError: unexpected standard output, contains: "[1757988765:571003][8779:0x7ff011eb6700], test_checkpoint_snapshot03.test_checkpoint_snapshot03.test_checkpoint_snapshot(row_string), file:test_checkpoint_snapshot03.wt_stable, eviction-server: [WT_VERB_EVICTION][WARNING]: Eviction took more than 1 minute (76611388us). Building disk image took 76590840us. History store wrapup took 5175us.
[2025/09/15 22:35:14.735] test_checkpoint_snapshot03.py: "
[2025/09/15 22:35:14.735] test_checkpoint_snapshot03.py:
[2025/09/15 22:35:14.735] test_checkpoint_snapshot03.py: ----------------------------------------------------------------------
[2025/09/15 22:35:14.735] test_checkpoint_snapshot03.py: Ran 3 tests in 1538.504s
[2025/09/15 22:35:14.735] test_checkpoint_snapshot03.py:
[2025/09/15 22:35:14.735] test_checkpoint_snapshot03.py: FAILED (failures=1)