[Bug] A stalled HStore node holds REST workers for minutes: store-client commit retry swallows interrupts
- Dominant language
- Java
- Stars
- 3.2k
- Forks
- 636
- Avg merge
- 3d 11h
- Merged PRs (30d)
- 14
Description
### Bug Type (问题类型)
server status (启动/运行异常)
### Before submit
- [x] 我已经确认现有的 [Issues](https://github.com/apache/hugegraph/issues) 与 [FAQ](https://hugegraph.apache.org/docs/guides/faq/) 中没有相同 / 重复问题 (I have confirmed and searched that there are no similar problems in the historical issue and documents)
### Environment (环境信息)
- Server Version: apache/hugegraph master `36811483`; the behaviour is identical in 1.7.0 and 1.5.0 (`HgStoreClientConst.NODE_MAX_RETRYING_TIMES = 10` and `HgStoreClientConfig.GRPC_DEFAULT_TIMEOUT_SECONDS = 100` are unchanged since 1.5.0)
- Backend: hstore, PD + 3 store nodes on 3 VMs (Debian, Temurin 17 for PD/store, Temurin 11 for the server), server with 16 REST workers (8 CPUs), `restserver.request_timeout` at its default 30 s
- Also observed on a separate POC deployment with `grpc.timeout.seconds=60`: `PUT /graph/vertices/batch` → 500 `DEADLINE_EXCEEDED: deadline exceeded after 59.97s ... remote_addr=:8500` in `HgStoreStreamBlockingStub.scanBatchOneShot`, after which the REST server stopped answering any request
### Expected & Actual behavior (期望与实际表现)
**Expected:** when one store node stops answering (GC pause, write stall, hung process), requests that touch its partitions fail after one gRPC deadline or after `restserver.request_timeout`, and the server keeps serving everything else.
**Actual:** every write whose commit lands on a partition of the unreachable store holds a REST worker thread for `11 × grpc.timeout.seconds + 38 s` (about 19 minutes on defaults, 12 minutes with 60 s), and `restserver.request_timeout` does not stop it. At a moderate write rate the worker pool fills within tens of seconds and `LoadDetectFilter` answers 503 to everything, reads and writes to healthy partitions included, and keeps doing so for minutes after the client stops writing.
Cause, `hg-store-client`, `NodeTxExecutor.retryingInvoke()`:
1. The commit is retried up to `NODE_MAX_RETRYING_TIMES = 10` (a constant, not configurable) with a sleep schedule of 1, 1, 1, 2, 3, 4, 5, 6, 7, 8 s, and every attempt is a blocking `HgStoreSessionBlockingStub.batch` call with the `grpc.timeout.seconds` deadline. After a `DEADLINE_EXCEEDED` the next attempt only waits the full deadline again.
2. The `InterruptedException` from `Thread.sleep` is caught, logged as `Failed to sleep`, and the loop continues. The interrupt that `restserver.request_timeout` sends to the Grizzly worker is therefore swallowed, and the REST request time limit is ineffective on exactly this path.
Related, not addressed here: a multi-id read (`HstoreTable.query` → `getWithBatch` → `batchPrefix` → one blocking `scanBatchOneShot` per store) has no retry and no isolation of a single store, so one unreachable node fails the whole read, including the ids that live on healthy stores. That is the path in the POC stack trace above; it does not change the conclusion, because the interrupt does work there.
**Reproduction** (deterministic, no need to wait for a real outage):
```
# 1. on one store node
kill -STOP $(pgrep -f "Dname=HugeGraphStore")
# 2. on the server: one POST /graph/vertices per second for 300 s, each in its own thread,
# and a probe GET /graph/vertices/"" every 2 s, also after the writes stop
# 3. kill -CONT
```
Measured on the cluster above with `grpc.timeout.seconds=20` so that one run fits in minutes:
| | master `36811483` | with the fix below |
|---|---|---|
| REST unavailable (probe gets 503) | 431 of 503 s | 12 of 300 s |
| REST still dead after the writer stopped | 200 s | 0 s |
| 300 writes | 27 × 201, 243 × 503, 23 × 500 | 131 × 201, 152 × 500 after 20.0 s, 7 × 503 |
| slowest write | 257 s (= 11 × 20 + 38) | 20.1 s |
| server log | `Failed to sleep` ×30, `reached the upper limit` ×30 | `Failed to sleep` 0, `Not retrying after` ×152 |
`kill -CONT` restores the cluster without a restart in both cases. Scripts and full logs: [hugegraph-validation, finding F15](https://github.com/SebastianGruza/hugegraph-validation/blob/master/docs/findings.md#f15).
**Proposed fix** (PR in preparation): in `retryingInvoke` abort the loop when the thread is interrupted (restoring the interrupt flag) and do not retry after `DEADLINE_EXCEEDED` or `CANCELLED`; keep retrying `UNAVAILABLE` and other transport errors as today, since #3130 relies on that. Separately worth considering: moving the attempt count and the schedule into `HgStoreClientConfig`.
### Vertex/Edge example (问题点 / 边数据举例)
Any vertex write whose id maps to a partition of the unreachable store; in the measurement, label `node` with `CUSTOMIZE_STRING` ids and no properties.
### Schema [VertexLabel, EdgeLabel, IndexLabel] (元数据结构)
`vertexLabel("node").useCustomizeStringId().create()`; the problem does not depend on the schema.
Contributor guide
Research direction
Start in hg-store-client at NodeTxExecutor.retryingInvoke(), then inspect HgStoreClientConst.NODE_MAX_RETRYING_TIMES and HgStoreClientConfig.grpc.timeout.seconds. Reproduce with a paused store and the issue's write and probe requests; done means interrupted or deadline-exceeded calls stop promptly, retries remain for transient transport errors, and healthy REST requests stay available.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- grpc, java
- Domain
- api, backend, distributed-systems
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Active
- Clarity
- Clearly specified
- Newbie friendliness
- 64/100