apache / apache/hugegraph

[Bug] A stalled HStore node holds REST workers for minutes: store-client commit retry swallows interrupts

Open
#3,199 1 comment 0 reactions 0 assignees View on GitHub
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

Open the contributing 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

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.