Siyao Meng created HDDS-16980:
---------------------------------
Summary: Concurrent hsync on a Ratis key returns normally after
the stream failed, and replaces the key's block list in OM with an empty one
Key: HDDS-16980
URL: https://issues.apache.org/jira/browse/HDDS-16980
Project: Apache Ozone
Issue Type: Bug
Reporter: Siyao Meng
Attachments: CR-7-fail-calls-in-progress-when-key-stream-fails.patch,
TestBugCR7HsyncReturnsAfterStreamFailed.java
h3. Mechanism
When a call on {{KeyOutputStream}} cannot recover from a block failure,
{{markStreamClosed}} drops the buffered data and the block list
({{BlockOutputStreamEntryPool.cleanup}}) and sets {{closed}}. {{write}},
{{flush}} and {{hsync}} check {{closed}} only when they are entered. With
concurrent calls allowed, a second call that passed the check before still runs
to its end, in one of two ways:
# Its own flush of the same block failed as well, and its {{handleException}}
gets the write lock after the first caller's. {{handleExceptionInternal}} finds
no buffered data, because the buffer pool was cleared, so it retries nothing
and returns. {{handleFlushOrClose}} loops, finds no current block and returns.
This is the wide window: the second call only has to be in its flush of the
block when the block fails.
# It read the current block and then waited for the write lock, which the first
caller's failure handling holds. That handling has cleaned up the block stream,
and {{RatisBlockOutputStream.hsync}} and {{BlockOutputStream.flush}} do nothing
on a cleaned up stream.
In both cases {{KeyOutputStream.hsync}} goes on to
{{BlockOutputStreamEntryPool.hsyncKey}}, which builds the block list from the
cleared entries. The list is empty, so it sends OM an hsync with the length of
the stream and no blocks. The key commit request ({{OMKeyCommitRequest}},
{{OMKeyCommitRequestWithFSO}}) stores that in the key table, where
{{OmKeyInfo.updateLocationInfoList}} replaces the block list. Then {{hsync}}
returns without an exception.
h3. Trigger
# {{ozone.client.hbase.enhancements.allowed=true}} and
{{ozone.client.key.write.concurrency}} greater than 1 or negative (run with
-1), so that calls on one key stream can overlap. The default configuration is
not affected. {{ozone.fs.hsync.enabled=true}} is needed for the OM half: a
second {{flush}} returns normally in the same way and sends nothing to OM.
# A block of a Ratis key fails in a way the client cannot recover from. Run
with every write answered with {{CLOSED_CONTAINER_IO}}, so that the replacement
blocks fail too and the default 5 retries are used up, and with
{{ozone.client.max.retries=0}}. Other ends of the failure handling (OM cannot
allocate another block, the thread is interrupted, the exception of HDDS-16975)
lead to the same {{markStreamClosed}} and are argued, not run.
# Two or more calls are in progress on that block, one of them an {{hsync}}. A
single thread always gets the exception (run).
HBase WAL sync threads call {{hflush}} on one stream concurrently (the stack in
HDDS-11374 shows {{FSHLog$SyncRunner}} in {{KeyOutputStream.hsync}} with write
concurrency -1), so there the third condition is the normal state. Not run with
HBase. Which cluster events use up the retries in practice (for example a
client that reaches OM but no datanode) is argued, not run.
The same code is in the release tags ozone-2.0.0 to ozone-2.2.1 (compared in
the tagged source, nothing run on a release).
h3. Impact
Run on a mini cluster with 5 datanodes, a real OM, an FSO bucket and the
default retry count, unmodified source. The write errors came from the client
side test hook {{XceiverClientManager.enableErrorInjection}}, which answered
every WriteChunk and PutBlock with {{CLOSED_CONTAINER_IO}}. The datanodes were
healthy.
* One call held: a file with 1000 bytes that were synced earlier and 500 more
bytes written, then two {{FSDataOutputStream.hsync}} calls, the first held in
that hook until the second was in the same flush. One call throws "Retry
request failed. retries get failed due to exceeded maximum allowed retries
number: 5", the other one returns normally. The 500 bytes are stored nowhere.
* After that the key in OM has length 1500 and no blocks, and a reader gets 0
bytes, so the 1000 bytes that an earlier {{hsync}} had acknowledged are not
readable either. The block is still listed in the writer's open key entry and
its data is still on the datanodes, but nothing reads through that entry.
{{recoverLease}} returns true, closes the file with length 0 and removes that
entry. The blocks were not queued for deletion in that run.
* The caller that got no exception finds out only with its next call ("Stream
is closed"). {{close}} on the failed stream returns normally.
* No call held: one writer thread and 5 threads calling {{hsync}} in a loop,
errors from second 1, 8 rounds. In every round the {{hsync}} calls that were in
progress (4 or 5) returned normally after the first call had failed, the key
was left with no blocks, and {{recoverLease}} closed the file with length 0.
Between 229632 and 393216 bytes had been acknowledged before the errors started.
For an application that treats a returned {{hsync}} as durable, such as the
HBase WAL, the data acknowledged by this and by earlier {{hsync}} calls is
silently lost to readers and to lease recovery.
h3. Reproduction
PASS, deterministic, unmodified source.
[^TestBugCR7HsyncReturnsAfterStreamFailed.java] ({{hadoop-ozone/client}}, about
one second) drives the unmodified write path through {{OzoneBucket.createKey}}
and {{OzoneOutputStream}} with mock datanodes and the mock OM. A subclass of
{{MockXceiverClientFactory}} answers every write with {{CLOSED_CONTAINER_IO}}
and holds the first caller, either in its flush or in its failure handling,
until the second caller is blocked behind it. No fixed sleeps. Cases: both ways
described above with the default retry count (one of the two {{hsync}} calls
returns normally, the key in the mock OM has the full length and reads back
empty), the second way without retries, {{flush}} and {{write}} as the second
call, and a control with a single caller, which gets the exception. A passing
test means the defect is present.
The mini cluster runs used temporary tests and are not attached.
h3. Suggested fix
The attached patch fixes the client. A check on the OM side could be a second
line of defence, for example against an hsync with a data size and no blocks.
It needs its own discussion and is not part of the patch.
h3. Patch
[^CR-7-fail-calls-in-progress-when-key-stream-fails.patch], against
031e76aa2c9a60b67185390b5b33499cbbb82e43. It also applies to master at
5181ff8ae81 (not built there).
* {{KeyOutputStream}} records when {{close}} has committed the key. A stream
that was closed without that has failed. {{write}}, {{flush}} and {{hsync}}
check for it again with the write lock held: {{write}} before it touches the
block pool, {{flush}} and {{hsync}} before they report success. {{hsync}} does
it in the same critical section as {{hsyncKey}}, so no block list is sent to OM
for a failed stream.
* To make that check exact, the stream is now always closed with the write lock
held: {{handleException}} closes it before it releases the lock when the
handling fails, and {{handleFlushOrClose}} takes the lock for
{{markStreamClosed}}.
* Behaviour: a call that is in progress when the stream fails now gets "Stream
is closed", also when its own data had already reached the datanodes. Nothing
changes without a failure. In particular a call that is in progress when
another thread's {{close}} commits the key does what it did before, for example
an {{hflush}} with the default configuration returns normally. Calls that
returned before the failure and {{close}} itself are not affected.
* Tests, in the existing {{TestKeyOutputStream}}:
{{testCallInProgressFailsWhenStreamFails}} (5 cases: {{hsync}} in both ways,
without retries, {{flush}}, {{write}}) also checks that an {{hsync}} before the
failure succeeds and that its data stays readable. Without the change all 5
cases fail with "Expecting code to raise a throwable".
{{testFlushInProgressSucceedsWhenStreamIsClosed}} (default configuration,
{{hflush}} against {{close}}) passes with and without the change.
* The tests do not fail without the two lock changes. Without the first one, a
loop of the case without retries still let the second {{hsync}} return normally
in 4 of 2000 runs (0 of 2000 with it). The second one is by reasoning.
* With the patch: the tests of {{hadoop-ozone/client}} (165) pass, checkstyle
is clean, and these mini cluster suites pass: {{TestHSync}} (42),
{{TestBlockOutputStream}} (24), {{TestBlockOutputStreamWithFailures}} (20),
{{TestFailureHandlingByClient}} (6), {{TestFailureHandlingByClientFlushDelay}}
(1), {{TestOzoneClientRetriesOnExceptions}} (2),
{{TestOzoneClientRetriesOnExceptionFlushDelay}} (1),
{{TestMultiBlockWritesWithDnFailures}} (2), {{TestClientRetryTimeout}} (4). 5
of the 6 cases of the reproduction then fail, because the second call throws.
The control still passes.
* Mini cluster with the patch: with one call held, the second {{hsync}} fails
with "Stream is closed", the key keeps its block and the 1000 synced bytes stay
readable. With no call held, no {{hsync}} returned normally after a failure in
3 rounds, and all bytes acknowledged before the failure stayed readable.
* Not repaired by the patch: {{recoverLease}} on such a file failed in the same
runs, for example with "ContainerID 6 does not exist", for a block that was
allocated during the failed retries and never written. The open key entry lists
the same blocks with and without the patch. Without the patch the key table has
no blocks left for the recovery to check. Lease recovery failing on never
written blocks of the open key is described in HDDS-16830.
The patch is independent of HDDS-16975 and applies before or after its patch.
The main changes are also independent of the patch of HDDS-16979, but both
patches add imports and a test at the end of {{TestKeyOutputStream}}, so the
one merged second needs a rebase of that file.
Found by code review of the Ratis key write path while validating fixes from
the TLA+ verification effort under HDDS-15926, on commit
031e76aa2c9a60b67185390b5b33499cbbb82e43. Checked against HDDS issues and
apache/ozone pull requests for duplicates before filing. The attached patch is
a proposal for review. Generated with Specula (Claude Opus 5.5).
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
