[Bug]: Main CN authentication stalls at logtail barriers during catalog contention, causing ANLI Proxy 20508 failures #29965

Is there an existing issue for the same bug?

• I have checked the existing issues.

Related to the receiver/catalog-contention investigation in #29275, but this report tracks normal authentication becoming unavailable before logtail recovery, not the previously observed 185-second forced-subscription recovery loop. No precise open issue for this Main incident was found.

Branch Name

main

Commit ID

• Observed: d382fd5fa2081fcff6bcf712160d4f93c541a05d.
• Latest main inspected: 5a5501b3e1048f3d19d96824cc68a62b7f0fcb07. Its pkg/vm/engine/disttae/cache/catalog.go is byte-identical to the incident version. This is a source check, not an end-to-end reproduction on latest main.
• Nightly harness: a8a59e037061a12c641ec409ba458d7af54ec6c7.

Other Environment Information

• Main nightly run 38149989746.
• ANLI TP write job 114584791861.
• Namespace: mo-main-family-38149989746-1.
• Affected TP CN: nightly-regression-dis-tp-cn-24x2z, UUID 62373261-3336-3733-3136-323265326130.
• Shared TN, one TP CN and two AP CNs; two Proxy pods both recorded backend authentication timeouts targeting the TP CN.
• Final resource artifact: all nine pods ready/running, restart counts zero. No OOMKilled evidence for this event.
• Failing scenario: insert_l2, eight writers, eight searchers, 200 rounds, 128 dimensions, 10 IVF lists.

Actual Behavior

The ANLI scenario reported 512 search failures and 508 write failures, with Proxy error 20508. Five subsequent DML scenarios were skipped. The same scenario had passed in the preceding run; this alone does not establish an introducing commit.

This is a real availability failure, not an ANN result-comparison failure. Proxy established backend connections but timed out after 10 seconds at read-auth-response. The generic text "possibly due to too many active transactions" must not be treated as proof of transaction-admission saturation.

Timeline

Times below are 2026-10-11 UTC; add eight hours for 2026-10-12 CST.

The two check.move.on to alpha-completion intervals are approximately 31.07s and 54.04s. Subtracting the logged alpha durations leaves approximately 30.11s and 47.77s outside alphaTask. Code places preparation before alphaTask, but these residuals are not isolated measurements of BTree lock-hold time or of GetTableByIdAndTime alone.

Incident profiles identify the blocking paths

Two TP goroutine aggregates were requested for 22:18:45-22:19:30 and 22:20:15-22:20:55 UTC. Both contain all three paths:

Authentication:
  MOServer.handshake -> MysqlProtocolImpl.Authenticate
  -> Session.AuthenticateUser -> prepareAuthenticationSnapshot
  -> acquireLogtailReadBarrier -> AcquireLogtailReadBarrier
  -> acquireAppliedLogtailReadBarrier -> logTailSubscriber.readBarrier
  -> LogtailClient.ReadBarrier -> runtime.selectgo

Background statistics:
  GetMOTableStatsExecutor -> tableStatsExecutor -> prepare
  -> getChangedTableList -> buildTablePairFromCache
  -> CatalogCache.GetTableByIdAndTime
  -> BTreeG.Ascend -> nodeScan -> GetTableByIdAndTime.func1

Logtail receiver:
  PushClient.receiveLogtails -> receiveOneLogtail
  -> dispatchUpdateResponse -> consumeUpdateLogTail
  -> applyToCatalogCache -> CatalogCache.InsertTable / DeleteTable
  -> setTableItemLocked -> BTreeG.SetHint -> sync.RWMutex.Lock

The first aggregate has weights 104 for the authentication-barrier stack, 8 for the statistics scan, and 8 for the receiver's catalog write-lock waits. The second has weights 134, 12 and 12 respectively. These are aggregate profile weights, not numbers of simultaneous goroutines or seconds of continuous lock ownership.

In the CPU profile selected for 22:18:40-22:19:30, stacks through the statistics GetTableByIdAndTime path account for 28.20 CPU-s of 119.82 sampled CPU-s (23.5%). This is an inclusive sampled CPU fraction, not wall-time attribution, whole-host utilization or proof that this path alone accounts for every failed connection.

Additional bounded metrics: TP RSS samples are about 31.1-37.7 GiB; the sampled wait-active queue is zero. The Go GC pause sum increases by about 39.8ms across the approximately four-minute sampled interval. These do not support a seconds-long stop-the-world pause or OOM as the explanation, but do not eliminate all CPU scheduling or allocation overhead.

Expected Behavior

Background catalog/statistics work should not prevent a healthy CN from making bounded progress on logtail consumption and ordinary connection authentication, causing repeated backend handshake deadline failures.

Any fix must preserve the authentication snapshot/read-barrier correctness guarantee. Bypassing that barrier, authenticating against stale catalog state, or merely increasing Proxy timeouts is not an established safe fix.

Steps to Reproduce

This report is based on the actual integration run and server profiles, not a synthetic timeout injection. A minimal deterministic end-to-end reproduction has not been completed.

1. Use the Main revision and the shared Family topology above.
2. Run the existing ANLI insert_l2 scenario through Proxy while the TP CN has the accumulated Family catalog and its normal background statistics task.
3. Capture connection-stage timing, authentication goroutines, catalog receiver stacks, statistics preparation cost and logtail receive-queue samples together.
4. Observe the documented 10-second backend authentication timeouts and client 20508 failures.

Next discriminating experiment: hold catalog contents and foreground connection workload fixed in an isolated test, compare normal statistics preparation against a narrowly controlled no-scan baseline, and measure catalog writer progress plus authentication/barrier latency. Do not disable statistics or correctness barriers on a shared production cluster merely to test this hypothesis.

Additional information

Exact-version source supports the mechanism

• GetTableByIdAndTime scans a name-ordered catalog BTree to find a table ID at a snapshot; the source explicitly documents O(n) lookup. Retained versions are traversed too. It has no context parameter.
• getChangedTableList repeats this lookup for returned table IDs; buildTablePairFromCache resolves each against the catalog.
• The pinned dependency, tidwall/btree v1.7.0 Ascend, retains the BTree read lock for the traversal and callbacks. SetHint requires its write lock. This is ordinary RWMutex contention, not evidence of a bug in the BTree implementation.
• prepareAuthenticationSnapshot acquires the logtail barrier before reading authentication catalog data.
• LogtailClient.Receive completes barrier responses while consuming the same stream. A receiver blocked applying an earlier catalog update cannot immediately consume later barrier responses.

Assessment: The handshake failures, authentication barrier waits, catalog receiver write-lock waits and repeated statistics scans are observed. The source explains how catalog scan contention can delay logtail and therefore authentication. Statistics-driven catalog contention is the leading initiating-cause hypothesis, not yet a uniquely proven cause for the entire incident. Aggregate stacks do not identify one continuously held lock, the exact catalog cardinality is not reconstructed, and no controlled intervention has yet removed this bottleneck while keeping the rest of the workload constant.

Existing-issue and regression boundary

• [Bug]: catalog logtail recovery abandons slow forced-flush subscriptions, pausing CN transactions for 185s #29275 already records catalog contention as a precursor, but its principal failure is long forced-subscription recovery. Here authentication fails before transaction pause, and the observed pause is only 5.1s. Link the investigations; do not label this as a reappearance of a closed recovery fix or duplicate the 185s claim.
• [Bug]: main stability LogService/Raft stalls, causing 25s WAL append and Proxy 20508 #29687 has similar Proxy symptoms with a LogService/Raft stall; that root cause is not established here.
• IDC-MO [Performance]: Measure and bound residual mo_table_stats load per CN #29240 was administratively closed as an unintended tracking item, not as a verified fix for this incident.
• [Bug]: CollectChanged returns historical checkpoint table IDs outside requested window #29339 fixed out-of-window table IDs from CollectChanged; it does not by itself remove the shown ID-lookup traversal and locking.
• No introducing PR has been identified. A prior successful run is insufficient to call this a newly introduced regression.
• No durable data-loss, wrong-result, leaked-transaction or vector-distance-algorithm claim is made.