[
https://issues.apache.org/jira/browse/CASSANDRA-21537?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18130081#comment-18130081
]
Patrick McFadin commented on CASSANDRA-21537:
---------------------------------------------
CI results for the current heads of [PR
#4970|https://github.com/apache/cassandra/pull/4970] (trunk) and [PR
#5290|https://github.com/apache/cassandra/pull/5290] (cassandra-6.0). Both
branches were rebased onto the current base. On trunk the only conflict was the
{{&& !log.isClosed()}} loop condition from 4da20e07e8, which is kept. The 6.0
branch is a clean cherry-pick of the same commits. Since the last round: the
rejection-message wording fix bbotella suggested, and a CHANGES.txt entry.
||Branch||Head||Job / build||Result||Tests||New tests||
|{{pmcfadin/CASSANDRA-21537/trunk}}|{{7db6e8f931}}|{{cassandra}} #52,
pre-commit|UNSTABLE, every cell ran|115,629 pass / 36 fail / 1,778 skip|57/57
pass|
|{{pmcfadin/CASSANDRA-21537/cassandra-6.0}}|{{f167cf2115}}|{{cassandra-6.0}}
#97, pre-commit|Every test cell ran; the pipeline pod was then lost to an EKS
node shutdown before the Summary stage. The summary below was rebuilt from the
archived {{test/output}} using the branch's own {{.build/ci}} scripts.|115,144
pass / 32 fail / 1,778 skip|57/57 pass|
Artifacts attached: [^CASSANDRA-21537-ci_summary-cassandra-52.html],
[^CASSANDRA-21537-results_details-cassandra-52.tar.xz],
[^CASSANDRA-21537-ci_summary-cassandra-6.0-97.html],
[^CASSANDRA-21537-results_details-cassandra-6.0-97.tar.xz]
*None of the failures is attributable to the patch.* The patch changes only
{{AbstractLocalProcessor}} plus its tests and CHANGES.txt.
* {{LocalRangesAllSettledBench}} (all three benchmarks, every JDK, both
branches): {{UTFDataFormatException: malformed input around byte 95}} while
deserializing the checked-in
{{cluster_metadata/CASSANDRA-21144_clustermetadata.gz}} snapshot. It reproduces
on unmodified {{origin/trunk}} at {{a82ffca224}}, the exact base of the trunk
branch, and on unmodified {{cassandra-6.0}} at {{67987d44c1}}. This is a
pre-existing break, separate from this ticket.
* Known flaky per [butler|https://butler.cassandra.apache.org/]:
** Accord {{Full/Interop/MixedReadAccordCQLTest#testMultipleShards}}
** {{IdenticalTopologyTest}}
** simulator-dtest: {{SingleNodeSingleTableASTTest}} ×3,
{{HarrySimulatorTest}}, {{AccordHarrySimulationTest}},
{{ShortAccordSimulationTest}}, {{ShortPaxosSimulationTest}},
{{EpochStressTest}}, {{TrivialSimulationTest}}
** {{CompactionStrategyManagerTest#testAutomaticUpgradeConcurrency}}
** {{UnifiedCompactionStrategyTest#testDropExpiredSSTables}}: 62 upstream
failures (trunk 33, 6.0 29)
** {{AccordTopologyMixupTest}}: 18 upstream failures (6.0 only in this run)
** {{AccordDeleteCommandStoreTest}}: 6 upstream failures (6.0 only in this run)
** {{ConnectionTest#testMessageDeliveryOnReconnect}}: butler links it to
CASSANDRA-16677 (trunk only in this run)
* Infrastructure, trunk only:
{{JMXFeatureTest#testMultipleNetworkInterfacesProvisioning}} (failed to bind a
port), and {{AutoRepairSchedulerTest}} (unterminated repair thread at suite
teardown, outside TCM).
{{ConcurrentSchemaCommitTest}} is load-sensitive: it drives 864 DDLs at
concurrency 48 against a 10s request deadline. It passed in every CI cell.
Locally it failed once, with 10 statements timing out on local admission, while
the laptop was running another in-JVM dtest suite in parallel. It passed on
rerun.
Reviewer still needed: Jon Haddad is a co-author, so this needs a +1 from a
committer other than the authors.
> Concurrent CREATE TABLE fails with "Could not perform commit after X attempts"
> ------------------------------------------------------------------------------
>
> 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
> Assignee: Patrick McFadin
> Priority: Normal
> Fix For: 6.0
>
> Attachments: CASSANDRA-21537-ci_summary-cassandra-31-1.html,
> CASSANDRA-21537-ci_summary-cassandra-31.html,
> CASSANDRA-21537-ci_summary-cassandra-52.html,
> CASSANDRA-21537-ci_summary-cassandra-6.0-97.html,
> CASSANDRA-21537-results_details-cassandra-31.tar.xz,
> CASSANDRA-21537-results_details-cassandra-52.tar.xz,
> CASSANDRA-21537-results_details-cassandra-6.0-97.tar.xz
>
> Time Spent: 40m
> Remaining Estimate: 0h
>
> 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
(v10.3.26#10030026)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
