[
https://issues.apache.org/jira/browse/CASSANDRA-21537?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Patrick McFadin updated CASSANDRA-21537:
----------------------------------------
Fix Version/s: 6.0-alpha1
> Concurrent CREATE TABLE fails with "Could not perform commit after 12
> attempts" while seconds of the request timeout remain
> ---------------------------------------------------------------------------------------------------------------------------
>
> Key: CASSANDRA-21537
> URL: https://issues.apache.org/jira/browse/CASSANDRA-21537
> Project: Apache Cassandra
> Issue Type: Bug
> Components: Cluster/Schema, Transactional Cluster Metadata
> Reporter: Patrick McFadin
> Priority: Normal
> Fix For: 6.0-alpha1
>
>
> Testing 6.0 locally on a single node, I started several clients at once and
> had
> each create its own killrvideo keyspace and a set of tables, the way a test
> suite or an
> app with a few workers does at startup.
> Some of those {{CREATE TABLE}} statements failed with:
> {noformat}
> Could not perform commit after 12 attempts. Time remaining: 4231ms
> {noformat}
> The statements were valid and the node was healthy. Re-running them worked.
> The
> part that looks wrong is the message itself: it gave up after 12 attempts
> while
> still having over 4 seconds of the request timeout left.
> For a user this means parallel schema setup fails intermittently, with an
> error
> that reads like a server problem rather than contention.
> h4. How to reproduce
> Single node, default configuration. Start N clients simultaneously; each
> creates
> its own keyspace, then 18 tables in it.
> ||Concurrent clients||Statements||Failed||
> |1, 2, 4|19 – 76|0|
> |6|114|1|
> |8|152|2 – 3|
> |22|418|10|
> |48|912|34|
> Loading the same schema from a *single* client never failed at any size, so
> this
> is about concurrency, not schema size.
> Failures start somewhere around 6 to 8 concurrent clients on this hardware; 1
> through 4 were clean in every run. Two independent sweeps agreed on that
> boundary, and the counts above for 6 and 8 come from those separate runs.
> Every one of the 168 failures in the first full sweep happened at exactly *12
> attempts*, with between {*}3345 ms and 5685 ms of the deadline still
> remaining{*}.
> Latency also degrades well before anything fails, p99 for successful
> statements
> goes from about 130 ms at low concurrency to 4–6 s at 8 workers and above.
> Measured in Docker: single node, one CMS member, RF=1, 4 CPU / 4 GB, JDK 21,
> default retry and timeout settings. This is a developer/CI-sized setup rather
> than a production cluster, and the client count where it starts failing will
> move with hardware, but the failure mode and the "12 attempts with seconds
> left" signature were identical in every run.
> h4. Cause
> I have Claude Opus 5 digging on this quite a bit and found that this is a
> combination of two issues:
> *The attempt cap is unrelated to the deadline.* In
> {{ClusterMetadataService.getRetryPolicy()}} ({{:727-731}}), a
> {{SCHEMA_CHANGE}} gets its deadline from {{request_timeout}} (10s by default)
> but takes its wait strategy from the shared {{Retry.DEFAULT_STRATEGY}}. That
> strategy comes from {{cms_retry_delay}}, whose default ends in {{retries=10}}
> ({{Config.java:205}}), giving {{maxAttempts = 11}}
> ({{RetryStrategy.java:215}}). So the attempt count runs out first and the
> request fails with time to spare.
> *Concurrent requests contend for the same epoch.* In
> {{AbstractLocalProcessor.commit()}}, each request reads the current highest
> consecutive epoch ({{:63}}) and derives the same next epoch ({{:113}}), so
> concurrent callers all attempt to CAS at {{E+1}}. One wins; the rest back off,
> fetch the log, and retry — burning attempts against the cap. The server error
> is
> built at {{:156-161}}.
> The node's own logging shows the contention: at 22 clients, 387 commits
> succeeded on the first attempt, with a tail running 2 through 11 attempts.
> Worth noting for anyone trying to work around it: raising
> {{cms_default_max_retries}} alone does nothing, because a non-null
> {{cms_retry_delay}} supplies the whole strategy and
> {{cms_default_max_retries}} is only consulted when it is null.
> h4. Versions
> Affected: {{cassandra-6.0}} (tested on a build of {{4066139d3f74}}) and
> {{trunk}} — the relevant files are identical between them.
> h4. Fix direction that I'm going in
> The attached branch contains a reproducing test only, not a fix.
> I did try the obvious narrow change — letting the schema retry policy run to
> its
> deadline instead of stopping at the attempt cap. It does remove the
> "gave up with time remaining" outcome: every remaining failure then reports
> {{Time remaining: 0ms}} after 13-15 attempts rather than stopping at 12 with
> seconds to spare. But I am not proposing it, for three reasons:
> * it does not reduce the contention, so statements still fail at higher
> concurrency — they just fail at the deadline instead of early;
> * requests now always run to the full deadline, so worst-case commit duration
> increases, and {{Retry.maybeSleep}} sleeps uninterruptibly;
> * getting it right without also changing the meaning of a configured
> {{cms_retry_delay}} is more delicate than it first looks.
> So the question is which direction is wanted:
> # *Let the schema policy run to its deadline.* Smallest change; removes the
> incoherence but not the contention, and lengthens the worst case.
> # *Coordinate proposals locally* so many request threads on one CMS member do
> not all race the same next epoch. Addresses the actual cause for the
> single-member case. Needs care around deadlines, shutdown, and CMS membership
> changes so queued work cannot be stranded.
> # *Return a contention-aware CAS result* so a lost race can rebase on the
> winner
> instead of going through a generic backoff-and-refetch cycle. Helps the
> multi-member case too, but changes a correctness-sensitive interface.
> Related: {{DistributedMetadataLogKeyspace.tryCommit}} currently flattens a
> genuine contention loss, a {{CasWriteTimeoutException}}, and any other
> throwable all to {{false}}, so the caller cannot tell them apart.
> Raising retry counts or {{rpc_timeout}} alone is not a fix — the first hides
> it
> while keeping the contention, and the second is what already fails.
> h4. Note on the attached test, and on existing coverage
> The attached {{ConcurrentSchemaCommitTest}} asserts that *every* submitted
> statement succeeds. That is deliberately a stronger oracle than this ticket's
> narrow complaint, so it will keep failing under contention even if only the
> attempt-cap incoherence is fixed. If the agreed scope is just "never stop
> before
> the deadline", the assertion should be narrowed to that before it is
> committed —
> I would rather agree the success criterion first than encode the wrong one.
> For contrast, {{DistributedLogTest.testConcurrentCommit()}} looks like it
> covers
> this area but does not: it catches and ignores every commit exception and only
> adds to its expected set after a success, so it can only confirm that
> already-successful operations are present.
> h4. Related
> CASSANDRA-19347 improved the wording of this same message family but not the
> underlying behaviour — its example shows {{Time remaining: 0ms}}, i.e. an
> actually-expired deadline, whereas here several seconds remain.
> CASSANDRA-20059 covers a similar deadline-versus-retry-bound mismatch
> elsewhere
> in TCM. Also CASSANDRA-21002, CASSANDRA-21501.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
