matrixorigin / matrixorigin/matrixone
[Bug]: TPCC 1000W/1000 terminals cross-CN pipeline timeout returns 20502
- Dominant language
- Go
- Stars
- 1.9k
- Forks
- 311
- Avg merge
- 1d 3h
- Merged PRs (30d)
- 768
Description
## Description
In the normal main TKE TPCC 1000 warehouses / 1000 terminals workload, several independent `STOCK_LEVEL` requests received `ErrorCode: 20502, backend connection closed`. Server logs show a five-second failure while a TP CN creates a pipeline MORPC backend to another live TP CN. The incident also affected CN heartbeat, lockservice, task service and log-service requests in the same time window.
## Environment
- Branch: `main`
- MatrixOne commit: `c61ed374a8a6daebc4e753a928cb63c584addb4c`
- Workflow revision: `dff1aaab05bd3cca5b2b7aa34c69d01f888ac62a`
- Deployment: TKE distributed topology, 3 TP CNs, 1 DN, 2 Proxies
- Namespace: `mo-main-commit-c61ed374a8-20260914`
- Failing job: https://github.com/matrixorigin/mo-nightly-regression/actions/runs/34860226012/job/104088638008
- Failure timestamp: 2026-09-14 18:37:13 UTC
## Steps to reproduce
1. Deploy the above main commit using the TKE nightly distributed topology.
2. Prepare TPCC data for 1000 warehouses.
3. Run the 1000-terminal TPCC transaction phase for five minutes with the standard regression workload mix.
4. Preserve all TP CN, DN, LogService and Proxy logs from at least 60 seconds before the first client error through recovery.
## Actual behavior
The 1000-terminal phase started at `18:36:57`. The following service degradation preceded the client-visible SQL failures:
```text
18:37:01 tp-cn-jqkcn (10.143.100.107): CN heartbeat -> context deadline exceeded
18:37:05 tp-cn-59s9b: lockservice failed to validate transactions -> backend connection closed
18:37:08 tp-cn-drn42: remote unlock / ISCP transaction finish -> context deadline exceeded
18:37:10 log-2: query cron task -> context deadline exceeded
18:37:13 tp-cn-59s9b pipeline client -> 10.143.100.107:6002
backend auto-create waited 5.000s
dial tcp4 10.143.100.107:6002: i/o timeout
18:37:13 five TPCC STOCK_LEVEL executions return 20502 backend connection closed
18:37:24+ tp-cn-jqkcn: task SQL, logger writes and frontend sessions -> context canceled / routine closed or busy
```
The exact server-side request failure was logged at `process/process.go:766` as `Failed to newMessageSenderOnClient sql=execute __mo_stmt_id_24, err=backend connection closed`; `__mo_stmt_id_24` is the TPCC `STOCK_LEVEL` query against `bmsql_stock`. The initiating MORPC error was:
```text
auto-create backend timed out: waited=5.000072847s timeout=5s
dial tcp4 10.143.100.107:6002: i/o timeout
connect to remote failed: rpc timeout
```
The client recorded exactly five unexpected `STOCK_LEVEL` failures at the same second. The workload completed its five-minute duration, but the runner correctly failed because `benchmarksql-error.log` contained those unexpected database errors.
## Expected behavior
A supported TPCC 1000-terminal workload must not expose internal cross-CN MORPC connection creation/timeout failures as `20502` to client transactions. A transient slow connection or a delayed peer must be bounded and recovered/isolated without cancelling unrelated in-flight TPCC requests.
## Stability and controls
- Reproducer observed: `1/1` run so far. Repetition is required to establish rate and commit range.
- Controls in the same job passed: TPCC 10W/10T, 10W/100T, 100W/100T and 100W/1000T.
- TPCC consistency verification completed successfully after the failing phase; no persistent data inconsistency was found.
- Pod restart count was zero for all TP CNs in the incident window. No OOM event or CPU CFS throttling was observed.
## Evidence
- Client errors: five `STOCK_LEVEL` requests at `18:37:13`, each with `20502 backend connection closed`.
- `tp-cn-59s9b` could not establish a MORPC pipeline backend to `tp-cn-jqkcn:6002` within five seconds.
- The same window contains independent lockservice, taskservice, CN-heartbeat and LogService deadline errors, so this is not a malformed TPCC statement or a test assertion issue.
- `tp-cn-jqkcn` had many FileService S3 read slow events around the onset (roughly 0.8-2.2 seconds). This is correlation only, not a confirmed root cause.
## Code analysis
This is related by symptom, but not proven duplicate of #26475. #26475 was fixed by #26473 and that merge is already contained in `c61ed374`. The previous incident was a lockservice local backend-create timeout at a 500 ms boundary; this incident is a five-second pipeline-client dial timeout to port 6002 during query execution. The current failure may therefore be an uncovered MORPC/pipeline availability path or a new regression.
The direct initiating component is still unproven: the evidence does not distinguish a delayed/unavailable `tp-cn-jqkcn` listener, network-path disruption, FileService-induced service stall, or another MORPC lifecycle transition.
## Regression coverage
The TKE nightly TPCC 1000W/1000T case already detects this failure. After a product fix, rerun this same workload repeatedly and require zero `20502`, zero CN heartbeat/lockservice timeout burst, and a successful consistency check. Preserve per-CN MORPC backend-create/connection metrics and logs for any recurrence.
## Related
- #26475 — similar TPCC 20502 symptom; closed after #26473, but different timeout/path
- #26473 — lockservice RPC lifecycle fix already contained in the tested commit
- #26090 — related MORPC timeout/connection-wide cancellation design issue
- #28080 — synchronized post-restore/clone connection-loss bursts; different trigger
Contributor guide
Assessment
This issue has not been assessed yet.