[
https://issues.apache.org/jira/browse/HDDS-16980?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Siyao Meng updated HDDS-16980:
------------------------------
Attachment: TestBugCR7HsyncReturnsAfterStreamFailed.java
> 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
> Priority: Critical
> 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]
