Describe the situation
On a CAS pool, a replica that refuses a relink ownership proof causes the receiving replica to log an Error with a full stack trace and error code NETWORK_ERROR. Under a write load made of many small parts this is not a rare event: in a controlled measurement, 240 of 455 relink proofs (53%) were refused, each producing one such Error entry. A four-minute alter suite run under --cas produced 455 of them.
Nothing is actually wrong when this happens, and this is not a performance report either. The refusal is the designed answer, the fetch is retried, and replication converges — lag stays flat at roughly 0.5s through a write burst rather than growing. Measured against the byte path it replaces, relink is still ~3x cheaper on the receiving side even while proofs are being refused: followers spend 1686ms obtaining 276 MiB under cas_policy against 5056ms under s3_policy on the same hardware and the same workload. So the retries cost far less than they save, and the only thing wrong is what the log says about them: Error, a stack trace, and NETWORK_ERROR all point a reader at the network stack.
The concrete cost is misdirected triage. This exact pattern sent an investigation of an unrelated alter suite failure down a multi-hour path chasing a non-existent network fault, because a healthy cluster under normal writes produces hundreds of Error lines saying a peer "did not prove" something. Anyone reading CI logs or a customer's clickhouse-server.err.log will draw the same wrong conclusion.
This issue:
- Emits
Error + stack trace + NETWORK_ERROR for an outcome that is expected and benign
- Fires on up to half of all relink fetches for a table being written to in small parts
- Is asymmetric: the sender logs the same event at
Debug, only the receiver escalates it
How to reproduce the behavior
Environment
Steps
-
Create a ReplicatedMergeTree on a cas_policy storage policy on all three replicas.
-
Write parts on replica 1 without stopping fetches on the followers, so writing and fetching overlap. Followers begin fetching within ~100 ms of the first insert. Keep the parts small and the inserts frequent — that is what keeps the ref lane busy relative to the number of proofs. Six tables written concurrently makes the effect obvious; one table shows it at a lower rate:
-- repeated 20 times, per table
INSERT INTO t0 SELECT number, toString(number) FROM numbers(1000);
- Count the
Error entries on the followers:
grep -c "did not prove it still holds the manifest" /var/log/clickhouse-server/clickhouse-server.log
A ready-made measurement exists as cas/tests/relink_efficiency.py, scenario live insert catch-up, in the regression suite.
Expected behavior
An expected, self-healing protocol outcome should not be logged at Error with a stack trace, and should not carry an error code that names a subsystem which is not involved. Debug or Trace would match the sender's own logging of the same event, and would match how routine the outcome is.
Actual behavior
On every refusal, the receiver logs:
<Error> default.t0 (...): auto DB::StorageReplicatedMergeTree::processQueueEntry(...):
Code: 210. DB::Exception: Source clickhouse1 did not prove it still holds the manifest
it offered for part all_1_1_0 by relink; the relink is abandoned and the fetch will be
retried later. (NETWORK_ERROR)
0. DB::Exception::Exception(...)
...
4. DB::DataPartsExchange::Fetcher::relinkPartToDisk(...)
5. DB::DataPartsExchange::Fetcher::fetchSelectedPart(...)
7. DB::StorageReplicatedMergeTree::fetchPart(...)
8. DB::StorageReplicatedMergeTree::executeFetch(...)
The sender logs the same event, at Debug:
<Debug> Relink confirm is unproven (unknown) for ref 'all_1_1_0' (part all_1_1_0,
manifest 1:52:1) in namespace 'cas-clickhouse1/store/08d/08d6399b-...@cas@'
This is expected behaviour, and that is the point
To be explicit so this is not mistaken for a correctness report: the refusal is intentional and correct.
CasRefLedger::confirmExactRef refuses whenever the table's ref lane is not quiescent:
// Rule 3 (lane quiescent) ...
// None of the three says anything about WHICH ref is affected, so all three are
// table-scoped refusals.
if (rt.lane_state != RefLaneState::Ready || !rt.pending.empty() || rt.leader_active)
return ConfirmAnswer::Unknown;The same function documents the trade deliberately — "the answer to anything a rule cannot establish is Unknown, which costs the receiver a retry and costs correctness nothing" — and is intentionally zero-I/O with a try_to_lock on state_mutex, because "anything it could be made to do is something a remote peer can make this writer do". Taxonomy row 3 in DataPartsExchange.cpp then throws rather than falling back to bytes, because a byte re-request would return to the same source whose state is in doubt.
All of that is sound, and the cost of the retries has been measured and is well below what relink saves over transferring bytes. The only thing being reported here is that a designed, expected, frequent outcome is surfaced to operators as an Error with a stack trace.
Suggested fix
Log the retry-later throw at Debug/Information instead of letting it surface as Error, or suppress the stack trace for this specific taxonomy row. The receiver already distinguishes this case explicitly, so the site is well-defined. Reserving Error for the outcomes that are genuinely not expected would make CAS logs usable for triage again.
Additional context
- Measurement:
cas/tests/relink_efficiency.py (Altinity/clickhouse-regression), scenarios live insert catch-up and relink vs byte transfer
- Rate depends on part size, not on writing as such: 240 of 455 (53%) with 1000-row parts from six concurrent writers, 4 of 44 (9%) with one writer, and 0–2 of 26 with 1M-row parts, where a long insert leaves the lane quiescent for most of its duration
- Impact on replication: none — lag stays flat (median ~0.5s) through a burst and all replicas converge
- Impact on throughput: relink stays ~3x cheaper than the byte path it replaces even with refusals present (1686ms vs 5056ms of follower fetch time for 276 MiB), so there is no performance defect underneath this report
Describe the situation
On a CAS pool, a replica that refuses a relink ownership proof causes the receiving replica to log an
Errorwith a full stack trace and error codeNETWORK_ERROR. Under a write load made of many small parts this is not a rare event: in a controlled measurement, 240 of 455 relink proofs (53%) were refused, each producing one suchErrorentry. A four-minutealtersuite run under--casproduced 455 of them.Nothing is actually wrong when this happens, and this is not a performance report either. The refusal is the designed answer, the fetch is retried, and replication converges — lag stays flat at roughly 0.5s through a write burst rather than growing. Measured against the byte path it replaces, relink is still ~3x cheaper on the receiving side even while proofs are being refused: followers spend 1686ms obtaining 276 MiB under
cas_policyagainst 5056ms unders3_policyon the same hardware and the same workload. So the retries cost far less than they save, and the only thing wrong is what the log says about them:Error, a stack trace, andNETWORK_ERRORall point a reader at the network stack.The concrete cost is misdirected triage. This exact pattern sent an investigation of an unrelated
altersuite failure down a multi-hour path chasing a non-existent network fault, because a healthy cluster under normal writes produces hundreds ofErrorlines saying a peer "did not prove" something. Anyone reading CI logs or a customer'sclickhouse-server.err.logwill draw the same wrong conclusion.This issue:
Error+ stack trace +NETWORK_ERRORfor an outcome that is expected and benignDebug, only the receiver escalates itHow to reproduce the behavior
Environment
26.6.2.20000.altinityantalyabuild_amd_release, PR [experimental] CAS (Content-addressed storage) over shared object storage for antalya-26.6 #2159, commitf76335f4d1a3933d80fe9812e47eca3f61eaa686)metadata_type = cas, per-replicaserver_root_id)Steps
Create a
ReplicatedMergeTreeon acas_policystorage policy on all three replicas.Write parts on replica 1 without stopping fetches on the followers, so writing and fetching overlap. Followers begin fetching within ~100 ms of the first insert. Keep the parts small and the inserts frequent — that is what keeps the ref lane busy relative to the number of proofs. Six tables written concurrently makes the effect obvious; one table shows it at a lower rate:
Errorentries on the followers:grep -c "did not prove it still holds the manifest" /var/log/clickhouse-server/clickhouse-server.logA ready-made measurement exists as
cas/tests/relink_efficiency.py, scenariolive insert catch-up, in the regression suite.Expected behavior
An expected, self-healing protocol outcome should not be logged at
Errorwith a stack trace, and should not carry an error code that names a subsystem which is not involved.DebugorTracewould match the sender's own logging of the same event, and would match how routine the outcome is.Actual behavior
On every refusal, the receiver logs:
The sender logs the same event, at
Debug:This is expected behaviour, and that is the point
To be explicit so this is not mistaken for a correctness report: the refusal is intentional and correct.
CasRefLedger::confirmExactRefrefuses whenever the table's ref lane is not quiescent:The same function documents the trade deliberately — "the answer to anything a rule cannot establish is
Unknown, which costs the receiver a retry and costs correctness nothing" — and is intentionally zero-I/O with atry_to_lockonstate_mutex, because "anything it could be made to do is something a remote peer can make this writer do". Taxonomy row 3 inDataPartsExchange.cppthen throws rather than falling back to bytes, because a byte re-request would return to the same source whose state is in doubt.All of that is sound, and the cost of the retries has been measured and is well below what relink saves over transferring bytes. The only thing being reported here is that a designed, expected, frequent outcome is surfaced to operators as an
Errorwith a stack trace.Suggested fix
Log the retry-later throw at
Debug/Informationinstead of letting it surface asError, or suppress the stack trace for this specific taxonomy row. The receiver already distinguishes this case explicitly, so the site is well-defined. ReservingErrorfor the outcomes that are genuinely not expected would make CAS logs usable for triage again.Additional context
cas/tests/relink_efficiency.py(Altinity/clickhouse-regression), scenarioslive insert catch-upandrelink vs byte transfer