Siyao Meng created HDDS-16982:
---------------------------------
Summary: TestFailureHandlingByClient crashes the test JVM when a
test runs after testBlockWritesWithDnFailures
Key: HDDS-16982
URL: https://issues.apache.org/jira/browse/HDDS-16982
Project: Apache Ozone
Issue Type: Sub-task
Components: test
Reporter: Siyao Meng
Assignee: Siyao Meng
When another test runs after
{{TestFailureHandlingByClient#testBlockWritesWithDnFailures}}, the forked test
JVM often exits while {{restartDownDataNodes}} restarts one of the datanodes
that test shut down:
{code}
[ERROR] ExecutionException The forked VM terminated without properly saying
goodbye. VM crash or System.exit called?
[ERROR] Crashed tests:
[ERROR] org.apache.hadoop.ozone.client.rpc.TestFailureHandlingByClient
{code}
{code}
ERROR ozoneimpl.OzoneContainer (HddsVolumeUtil.java:loadVolume(114)) - Load db
store for HddsVolume .../datanode-7/data-0/hdds failed
java.io.IOException: Can't init db instance under path
.../datanode-7/data-0/hdds/<clusterId>/DS-.../container.db for volume DS-...
Caused by: org.rocksdb.RocksDBException: lock hold by current process, acquire
time 1791878330 acquiring thread 140218196805312: .../container.db/LOCK: No
locks available
ERROR volume.HddsVolume (HddsVolume.java:check(289)) - Volume
.../datanode-7/data-0/hdds failed to access RocksDB: RocksDB parent directory
is null, the volume might not have been loaded properly.
ERROR statemachine.DatanodeStateMachine
(DatanodeStateMachine.java:handleFatalVolumeFailures(410)) -
DatanodeStateMachine Shutdown due to too many bad volumes, ...
INFO util.ExitUtil (ExitUtil.java:terminate(241)) - Exiting with status 1:
ExitException
{code}
h3. Root cause
HDDS-16224 changed {{testBlockCountOnFailures}} to read block data through
{{waitForBlockContainer}}, which polls every datanode in
{{cluster.getHddsDatanodes()}} and calls {{BlockUtils.getDB}} on each replica.
That list still contains the two datanodes {{testBlockWritesWithDnFailures}}
has just shut down. Their in memory {{ContainerSet}} still has the container,
but their per volume RocksDB was already closed and removed from
{{DatanodeStoreCache}} during shutdown. {{DatanodeStoreCache.getDB}} silently
opens a new instance on a cache miss and keeps it in the static cache, so the
test reopens the stopped datanode's {{container.db}} and holds its {{LOCK}}.
When {{restartDownDataNodes}} then restarts that datanode,
{{HddsVolume.loadDbStore}} opens the same DB uncached, fails with {{lock hold
by current process}}, and sets {{dbLoadFailure}}. The following volume check
fails the only data volume, and
{{DatanodeStateMachine.handleFatalVolumeFailures}} calls
{{ExitUtil.terminate}}, which exits the test JVM.
Evidence from 200 iterations of the class (two flaky test check runs, with and
without HDDS-16967): all 145 crashes show this lock error, every one right
after {{testBlockWritesWithDnFailures}}, and the RocksDB lock holder's acquire
time is within one second of the failed open in every case, i.e. the lock is
taken during the test, not by the old datanode instance.
The regular integration split rarely hits it because
{{testBlockWritesWithDnFailures}} is the last test it runs in this class, so no
restart follows. It shows up whenever the whole class runs with {{-Dtest}},
which also includes the {{@Flaky}} {{testDatanodeExclusionWithMajorityCommit}},
e.g. in the flaky test check workflow (about 73 of 100 iterations crash on
master).
h3. Fix
Skip stopped datanodes in {{waitForBlockContainer}} ({{if (dn.isStopped())
continue;}}), so the test never reopens the DB of a datanode it has shut down.
- https://github.com/smengcl/hadoop-ozone/actions/runs/38376787117 (master)
- https://github.com/smengcl/hadoop-ozone/actions/runs/38362647581 (with
HDDS-16967)
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
