[jira] [Commented] (IGNITE-29192) Fix flaky IgnitePdsCheckpointSimulationWithRealCpDisabledTest.testCheckpointSimulationMultiThreaded

["Ignite TC Bot (Jira)" <ji...@apache.org>]

    [ https://issues.apache.org/jira/browse/IGNITE-29192?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18130411#comment-18130411 ] 

Ignite TC Bot commented on IGNITE-29192:
----------------------------------------

{panel:title=Branch: [pull/13729/head] Base: [master] : No blockers found!|borderStyle=dashed|borderColor=#ccc|titleBGColor=#D6F7C1}{panel}
{panel:title=Branch: [pull/13729/head] Base: [master] : No new tests found!|borderStyle=dashed|borderColor=#ccc|titleBGColor=#F7D6C1}{panel}
[TeamCity *--> Run :: All* Results|https://ci2.ignite.apache.org/viewLog.html?buildId=9432477&buildTypeId=IgniteTests24Java8_RunAll]
{color:#ffffff}tcbot-analysis-comment chainBuildId=9432477 rerunBuildIds=none{color}

> Fix flaky IgnitePdsCheckpointSimulationWithRealCpDisabledTest.testCheckpointSimulationMultiThreaded
> ---------------------------------------------------------------------------------------------------
>
>                 Key: IGNITE-29192
>                 URL: https://issues.apache.org/jira/browse/IGNITE-29192
>             Project: Ignite
>          Issue Type: Bug
>            Reporter: Dmitry Werner
>            Assignee: Dmitry Werner
>            Priority: Minor
>              Labels: MakeTeamcityGreenAgain
>             Fix For: 2.19
>
>          Time Spent: 10m
>  Remaining Estimate: 0h
>
> Success Rate: 78.4% (Last 102 Runs) 22 failed, 80 successful
> [https://ci2.ignite.apache.org/test/1116565989146548944?currentProjectId=IgniteTests24Java8&branch=%3Cdefault%3E]
> *Root cause*
> The test runs in two phases on the same persistence directory. In phase 1 it logs a CheckpointRecord, saves the returned WALPointer start (which lands in WAL segment 0), writes 1000 pages across 20 simulated checkpoints with AlwaysWriteFullPages=true and WalMode=LOG_ONLY, then stops the node. In phase 2 it restarts the node and calls wal.replay(start).
> The test never sets maxWalArchiveSize, so the default DFLT_WAL_ARCHIVE_MAX_SIZE of 1 GiB applies (DataStorageConfiguration.java:130) and the background FileCleaner worker is active.
> Two facts make the failure possible:
> 1. The cleaner wakes up at half the limit, not at 1 GiB. FileCleaner blocks in SegmentArchiveSizeStorage.awaitExceedMaxSize(minWalArchiveSize) (FileWriteAheadLogManager.java:3304, SegmentArchiveSizeStorage.java:154), where minWalArchiveSize = maxWalArchiveSize / 2 = 512 MB (FileWriteAheadLogManager.java:3656-3663). During phase 1 the 8 update threads write full-page snapshots non-stop, and the WAL grows past ~9 segments (~576 MB), so the cleaner becomes eligible.
> 2. Segment 0 loses its protection only at the end of the test. While checkpoints are disabled, the stale lastCheckpointPtr (initially WALPointer(0,0,0), FileWriteAheadLogManager.java:383) actually protects segment 0: the cleaner's gate fileDesc.idx >= lastCheckpointPtr.index() breaks the scan, and doCheckpoint() is skipped entirely while disabled — even forced checkpoints are merely rescheduled (Checkpointer.java:283-289). The protection is lifted when the test re-enables checkpoints in the finally block (dbMgr.enableCheckpoints(true) before stopAllGrids(false)): a real checkpoint runs at the WAL tail (segment ~8), and CheckpointWorkflow.markCheckpointEnd calls wal.notchLastCheckpointPtr(checkpointMark) (CheckpointWorkflow.java:571, FileWriteAheadLogManager.java:1155), advancing lastCheckpointPtr to index ~8. Segments 0..7 are now all "obsolete" from the cleaner's point of view, and its scan always marks the oldest unprotected segment for deletion ("Ensure that there will be exactly removed at least one segment", FileWriteAheadLogManager.java:3315-3327). The test's start pointer is never reserved, so segment 0 is deleted if the cleaner wins the race against node shutdown.
> On restart the archive starts at segment 1, so RecordsIterator.init() throws IgniteCheckedException: WAL history is too short [descs[0].idx=1, start.idx=0] (FileWriteAheadLogManager.java:2957), which is exactly the failure captured in CI: testCheckpointSimulationMultiThreaded:192->verifyReads:674 with descs=idx 1..8, start=WALPointer [idx=0, fileOff=9791920, len=41].
> This is a timing-dependent race between the FileCleaner's truncation and stopAllGrids() in the window after checkpoints are re-enabled: if the cleaner gets scheduled in that window the test fails, otherwise segment 0 survives and the test passes. That explains the flakiness on fast CI agents.
> *Fix*
> One line in getConfiguration — disable WAL archive truncation so the FileCleaner never starts and segment 0 is guaranteed to survive until phase 2:
> setDataStorageConfiguration(
>     new DataStorageConfiguration()
>         .setCheckpointFrequency(500)
>         .setWalMode(WALMode.LOG_ONLY)
>         .setAlwaysWriteFullPages(true)
>         .setMaxWalArchiveSize(DataStorageConfiguration.UNLIMITED_WAL_ARCHIVE) // add this
>         .setDefaultDataRegionConfiguration(...))
> With UNLIMITED_WAL_ARCHIVE the manager is created in unlimited mode (walArchiveUnlimited(), FileWriteAheadLogManager.java:3253), the FileCleaner worker is never constructed or started (its constructor asserts !walArchiveUnlimited(), :3295), so no deletion path exists at all and the fix deterministically removes the race rather than just shrinking it.
> This is the same pattern already used by sibling PDS tests that replay WAL after a restart (IgnitePdsStartWIthEmptyArchive, IgnitePdsReserveWalSegmentsTest, IgniteLocalWalSizeTest, IgniteWalRebalanceLoggingTest). It is safe for all five tests in the class — none depend on archive truncation, each runs in a clean persistence dir wiped by beforeTest/afterTest, and the largest WAL footprint is ~9-10 segments × 64 MB ≈ a few hundred MiB.



--
This message was sent by Atlassian Jira
(v10.3.26#10030026)