[
https://issues.apache.org/jira/browse/IGNITE-29141?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Dmitry Werner updated IGNITE-29141:
-----------------------------------
Description:
DistributedConfigurationPersistentTest.testReadLocalValueOnInactiveGrid fails
with:
java.lang.AssertionError: expected:<2> but was:<0>
at org.junit.Assert.fail(Assert.java:89)
at org.junit.Assert.failNotEquals(Assert.java:835)
at org.junit.Assert.assertEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:633)
at
org.apache.ignite.testframework.junits.JUnitAssertAware.assertEquals(JUnitAssertAware.java:90)
at
org.apache.ignite.internal.processors.configuration.distributed.DistributedConfigurationPersistentTest.testReadLocalValueOnInactiveGrid(DistributedConfigurationPersistentTest.java:99)
https://ci2.ignite.apache.org/test/520877418581486337?currentProjectId=IgniteTests24Java8&branch=%3Cdefault%3E
*Symptom*
The test propagates a property value 2, calls stopAllGrids(), restarts node 0,
and reads the property from persistent storage
(DistributedConfigurationPersistentTest.java:91-99). After the restart the
value is 0. The restart log shows "Ignite node stopped in the middle of
checkpoint" — a consequence of the same hard stop, not the cause.
*Root cause*
A race between the async durable write of the distributed metastorage and the
hard (cancel=true) node stop used by the test:
1. propagate(2L) returns as soon as the discovery ACK arrives, i.e. after
in-memory application on all nodes — it does not wait for durability. The write
future is completed in onAckMessage upon DistributedMetaStorageUpdateAckMessage
(DistributedMetaStorageImpl.java:1106-1120); the ack is the discovery SPI ack
of the DiscoveryCustomMessage (DistributedMetaStorageUpdateMessage.java:34,77;
future prepared in startWrite, DistributedMetaStorageImpl.java:996-1011).
2. The durable write to the local metastore (WAL record + B+tree in
metastoreMemPlc) is performed asynchronously by the dms-writer thread:
completeWrite → dataWriter.addUpdateTask(histItem)
(DistributedMetaStorageImpl.java:1191-1192 → DmsDataWriter.java:129-140).
3. The test calls stopAllGrids(), which stops nodes with cancel=true
(GridAbstractTest.java:1595-1600). That reaches
DistributedMetaStorageImpl.onKernalStop(true) → stopWorker(true)
(DistributedMetaStorageImpl.java:287-311) → DmsDataWriter.cancel(true) →
clearQueue() (DmsDataWriter.java:177-183), silently discarding the
not-yet-executed metastore write of value 2.
4. Hence no WAL record for 2 ever exists. WAL records of the metastore survive
process stop and are replayed on recovery (MetaStorage.writeRaw,
MetaStorage.java:425-455; replay of METASTORE_DATA_RECORD →
metaStorage.applyUpdate(...), GridCacheDatabaseSharedManager.java:2716-2721),
so had the task executed, the value would have survived. On restart the
metastore still holds 0 from the earlier propagate(0L), and registerProperty
actualizes the property to 0 (DistributedConfigurationProcessor.java:271-281).
Why flaky: usually the tiny dms-writer task wins the race; on a loaded CI agent
the stop wins instead. The same pattern (propagate → stopAllGrids() → restart →
expect 2) exists in testSuccessClusterWideUpdate and
testRegisterPropertyBeforeOnReadyForReadHappened of the same class.
*Fix*
Replace stopAllGrids() with stopAllGrids(false) (graceful stop) in the three
tests (DistributedConfigurationPersistentTest.java:59,93,136). With
cancel=false, DmsDataWriter.cancel appends its STOP marker after the pending
tasks of the FIFO queue (DmsDataWriter.java:185, LinkedBlockingQueue in
IgniteAsyncObjectHandler.java:35), so all pending metastore writes are executed
before the worker exits, and the graceful stop also performs a final
checkpoint. No production code changes.
was:https://ci2.ignite.apache.org/test/520877418581486337?currentProjectId=IgniteTests24Java8&branch=%3Cdefault%3E
> Fix flaky
> DistributedConfigurationPersistentTest.testReadLocalValueOnInactiveGrid
> ---------------------------------------------------------------------------------
>
> Key: IGNITE-29141
> URL: https://issues.apache.org/jira/browse/IGNITE-29141
> Project: Ignite
> Issue Type: Bug
> Reporter: Dmitry Werner
> Assignee: Dmitry Werner
> Priority: Minor
>
> DistributedConfigurationPersistentTest.testReadLocalValueOnInactiveGrid fails
> with:
> java.lang.AssertionError: expected:<2> but was:<0>
> at org.junit.Assert.fail(Assert.java:89)
> at org.junit.Assert.failNotEquals(Assert.java:835)
> at org.junit.Assert.assertEquals(Assert.java:647)
> at org.junit.Assert.assertEquals(Assert.java:633)
> at
> org.apache.ignite.testframework.junits.JUnitAssertAware.assertEquals(JUnitAssertAware.java:90)
> at
> org.apache.ignite.internal.processors.configuration.distributed.DistributedConfigurationPersistentTest.testReadLocalValueOnInactiveGrid(DistributedConfigurationPersistentTest.java:99)
> https://ci2.ignite.apache.org/test/520877418581486337?currentProjectId=IgniteTests24Java8&branch=%3Cdefault%3E
> *Symptom*
> The test propagates a property value 2, calls stopAllGrids(), restarts node
> 0, and reads the property from persistent storage
> (DistributedConfigurationPersistentTest.java:91-99). After the restart the
> value is 0. The restart log shows "Ignite node stopped in the middle of
> checkpoint" — a consequence of the same hard stop, not the cause.
> *Root cause*
> A race between the async durable write of the distributed metastorage and
> the hard (cancel=true) node stop used by the test:
> 1. propagate(2L) returns as soon as the discovery ACK arrives, i.e. after
> in-memory application on all nodes — it does not wait for durability. The
> write future is completed in onAckMessage upon
> DistributedMetaStorageUpdateAckMessage
> (DistributedMetaStorageImpl.java:1106-1120); the ack is the discovery SPI ack
> of the DiscoveryCustomMessage
> (DistributedMetaStorageUpdateMessage.java:34,77; future prepared in
> startWrite, DistributedMetaStorageImpl.java:996-1011).
> 2. The durable write to the local metastore (WAL record + B+tree in
> metastoreMemPlc) is performed asynchronously by the dms-writer thread:
> completeWrite → dataWriter.addUpdateTask(histItem)
> (DistributedMetaStorageImpl.java:1191-1192 → DmsDataWriter.java:129-140).
> 3. The test calls stopAllGrids(), which stops nodes with cancel=true
> (GridAbstractTest.java:1595-1600). That reaches
> DistributedMetaStorageImpl.onKernalStop(true) → stopWorker(true)
> (DistributedMetaStorageImpl.java:287-311) → DmsDataWriter.cancel(true) →
> clearQueue() (DmsDataWriter.java:177-183), silently discarding the
> not-yet-executed metastore write of value 2.
> 4. Hence no WAL record for 2 ever exists. WAL records of the metastore
> survive process stop and are replayed on recovery (MetaStorage.writeRaw,
> MetaStorage.java:425-455; replay of METASTORE_DATA_RECORD →
> metaStorage.applyUpdate(...), GridCacheDatabaseSharedManager.java:2716-2721),
> so had the task executed, the value would have survived. On restart the
> metastore still holds 0 from the earlier propagate(0L), and registerProperty
> actualizes the property to 0 (DistributedConfigurationProcessor.java:271-281).
> Why flaky: usually the tiny dms-writer task wins the race; on a loaded CI
> agent the stop wins instead. The same pattern (propagate → stopAllGrids() →
> restart → expect 2) exists in testSuccessClusterWideUpdate and
> testRegisterPropertyBeforeOnReadyForReadHappened of the same class.
> *Fix*
> Replace stopAllGrids() with stopAllGrids(false) (graceful stop) in the three
> tests (DistributedConfigurationPersistentTest.java:59,93,136). With
> cancel=false, DmsDataWriter.cancel appends its STOP marker after the pending
> tasks of the FIFO queue (DmsDataWriter.java:185, LinkedBlockingQueue in
> IgniteAsyncObjectHandler.java:35), so all pending metastore writes are
> executed before the worker exits, and the graceful stop also performs a final
> checkpoint. No production code changes.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
