Patrick McFadin created CASSANDRA-21537:
-------------------------------------------
Summary: 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
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]
