apache / apache/hugegraph

[Bug][HStore] Server exits 1 on cold start when Stores miss the 38s partition-lookup retry ceiling

Open
#3,203 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] I have confirmed and searched that there are no similar problems in the historical issues and documents.

### Environment (环境信息)

- Server Version: `hugegraph/server:latest` published image, built 2026-09-08, `hg-store-client-1.7.0.jar`. Also seen on images built from master `60c8803d` and from `6ec19838`.
- Backend: HStore, 3 PD + 3 Store + 3 Server, replica count 3
- OS: 12 CPUs, 15 G RAM, Ubuntu, Kubernetes v1.37.0 (kind), Docker 29.5.3
- Data Size: none, this happens on a completely empty first install

### Expected & Actual behavior (期望与实际表现)

**Expected.** On a cold start of a distributed cluster, a Server that finds the Stores have
not yet registered with PD waits for them and then starts.

**Actual.** The Server asks PD for partition information, gets
`error code = 105, The number of active stores is less then 3`, retries **10 times over 38
seconds**, hits a hard retry ceiling, and the JVM **exits 1**. Under Kubernetes the container
is restarted and usually succeeds on the second attempt, so the cluster ends up healthy and
the only lasting trace is `RESTARTS: 1`. Outside an orchestrator that restarts it, the Server
stays down.

This is a startup race, not a timeout. It is not related to the entrypoint startup budget
from #3186: the log contains no `The operation timed out(...)` line, and the value was 450 s
here.

![The Server's retry window is a fixed 38 s from T+42 to T+80; Stores registering inside it start the Server, after it the Server exits 1](https://raw.githubusercontent.com/bitflicker64/hugegraph/images/issue-3203/.github/images/issue-3203-retry-window.svg)

Case B is the reproduction detailed below. Case A stands for the successful path, which is
what the other two Servers on that same install did; its T+64 s is illustrative, while the
fixed timings (T+42, T+80, T+85) are measured.

#### Timeline from one reproduction

| Time | Event |
|---|---|
| 09:44:28 | Server containers start |
| 09:44:38 to 09:44:44 | PD pods start, 10 to 16 s **after** the Server |
| 09:44:39 to 09:44:45 | Store pods start |
| 09:45:11 | Server JVM finishes booting (~42 s) and requests partition information |
| 09:45:11 to 09:45:49 | `error code = 105` x10, backoff 1,1,1,2,3,4,5,6,7,8 s = **38 s** |
| 09:45:49 | `NodeTxExecutor - the number of retries reached the upper limit : 10` |
| 09:45:54 | container **exits 1**, total lifetime 85 s |

#### Log and stack trace

```
2026-09-10 09:45:11 [main] [ERROR] o.a.h.s.c.HgStoreNodePartitionerImpl - An error occurred
while getting partition information :PD request error, error code = 105,
msg = The number of active stores is less then 3
2026-09-10 09:45:11 [main] [INFO] o.a.h.s.c.NodeTxExecutor - Waiting 1 seconds for the next try.
... 10 attempts, backoff growing to 8 s ...
2026-09-10 09:45:49 [main] [ERROR] o.a.h.s.c.NodeTxExecutor - the number of retries reached
the upper limit : 10,caused by:
java.lang.RuntimeException: PD request error, error code = 105,
msg = The number of active stores is less then 3
at org.apache.hugegraph.store.client.HgStoreNodePartitionerImpl.partition(HgStoreNodePartitionerImpl.java:87) ~[hg-store-client-1.7.0.jar:1.7.0]
at org.apache.hugegraph.store.client.NodeTxSessionProxy.doPartition(NodeTxSessionProxy.java:865) ~[hg-store-client-1.7.0.jar:1.7.0]
at org.apache.hugegraph.store.client.NodeTxSessionProxy.toNodeTkvList(NodeTxSessionProxy.java:778) ~[hg-store-client-1.7.0.jar:1.7.0]
at org.apache.hugegraph.store.client.NodeTxSessionProxy.getNodeStream(NodeTxSessionProxy.java:921) ~[hg-store-client-1.7.0.jar:1.7.0]
at org.apache.hugegraph.store.client.NodeTxSessionProxy.lambda$createTable$20(NodeTxSessionProxy.java:321) ~[hg-store-client-1.7.0.jar:1.7.0]
at org.apache.hugegraph.store.client.NodeTxExecutor.lambda$isAllTrue$12(NodeTxExecutor.java:344) ~[hg-store-client-1.7.0.jar:1.7.0]
at org.apache.hugegraph.store.client.NodeTxExecutor.lambda$retryingInvoke$15(NodeTxExecutor.java:381) ~[hg-store-client-1.7.0.jar:1.7.0]
```

The restarted container hits the same error **9 more times** and then succeeds, because by
then the Stores have registered.

#### Why it is intermittent

It is a race between how long the Stores take to register with PD and a fixed 38 second
budget that begins about 42 seconds after the Server container starts. Rates observed across
four campaigns on two different hosts:

| Run | Host | Fresh Server starts | Failed |
|---|---|---|---|
| 2026-09-05 | A | 3 | 1 |
| 2026-09-10 run 1 | B | 3 | 0 |
| 2026-09-10 run 2 | B | 3 | 1 |
| 2026-09-10 F1 run | B | 3 | 1 |
| **total** | | **12** | **3** |

So **3 of 12 fresh Server starts** failed, and **3 of the 4 installs** produced at least one
crashed Server. The per-install figure is the one an operator meets.

Earlier campaigns saw a similar symptom that is deliberately **not** counted above. On
2026-08-29, two of six Server starts exited 1 on install, but each ran about 2 min 45 s
before dying, which fits the 120 s entrypoint self-kill of #3186 rather than this 38 s retry
ceiling, and the logs were lost so neither can be attributed. #3187 has since fixed that
one. If those two turn out to be this bug as well the rate is higher, not lower.

*(Corrected after first posting. The first two rows originally read 6/2 and 10/0. The 6/2
was carried over from #3186, which is the entrypoint's 120 s self-kill and a different
failure, and the 10 was a pod count rather than a count of Server starts. Every campaign
deployed exactly 3 Servers.)*

**It does not reproduce on pod replacement.** 66 Server replacements against an already
running cluster produced zero failures, because a replacement Server asks PD and gets a
straight answer in about 16 seconds. Only a cold cluster has the window. Anyone trying to
reproduce this must recreate the whole cluster, not restart a Server.

### Steps to reproduce

1. Deploy 3 PD + 3 Store + 3 Server on Kubernetes, all at once, with no ordering between them.
2. Watch the Server pods on the very first install.
3. Repeat the full install a few times. Three of the four installs observed so far showed
at least one Server with `RESTARTS: 1` and `lastState.terminated.exitCode: 1`.

### A note on diagnosing this

The message an operator actually sees is only:

```
Connecting to HugeGraphServer (http://0.0.0.0:8080/graphs)...........Starting HugeGraphServer failed
See /hugegraph-server/logs/hugegraph-server.log for HugeGraphServer log output.
```

That file is inside the container and the container is gone, so `kubectl logs --previous`
returns the line above and nothing else. The stack trace in this report was only obtainable
by mounting a volume at `/hugegraph-server/logs` before the first boot, so the crashed run's
log survived the restart. **Logging the fatal startup cause to stdout would make this class
of failure diagnosable without that trick.**

### Suggested direction

These are suggestions rather than a diagnosis of the right fix:

1. The retry ceiling is `HgStoreClientConst.NODE_MAX_RETRYING_TIMES = 10`
(`hugegraph-store/hg-store-client/.../util/HgStoreClientConst.java:48`), used only by
`NodeTxExecutor` at lines 376 and 383. Nothing reads it from configuration or the
environment, so 38 seconds is the whole budget an operator gets. A cold cluster bootstrap
can reasonably take longer than that. Either make the budget configurable, or use a longer
one on the bootstrap path where "stores not registered yet" is an expected transient
rather than a fault.
2. Treat `error code = 105` during startup as "not ready yet" rather than as a retryable
failure with a short ceiling, since it is precisely the condition that resolves on its own.
3. Log the terminal cause to stdout, per the note above.

Orchestration can also side-step this by not starting the Server until PD reports the
expected number of active stores. I will carry that as a gate in the Helm chart in #3131 /
apache/hugegraph#3132, but it is a workaround for the retry ceiling, not a fix for it.

### Related

- #3124, same component family (`HgStoreNodePartitionerImpl`, `NodeTxExecutor`) but a
different trigger: stale DNS after Store pod replacement, not a cold-start race.
- #3123, the storage wait binding to the first PD that answers.
- #3186, the entrypoint startup timeout. Explicitly **not** the cause here.
- #3131, the Helm chart, where the orchestration-side gate would live.

### Vertex/Edge example (问题点 / 边数据举例)

Not applicable, the cluster is empty.

### Schema [VertexLabel, EdgeLabel, IndexLabel] (元数据结构)

Not applicable, the failure happens before any schema exists.

Contributor guide

Open the contributing guide

Research direction

Start with hugegraph-store/hg-store-client/.../util/HgStoreClientConst.java:48 and the retry handling in NodeTxExecutor at lines 376 and 383. Reproduce a fresh 3-PD, 3-Store, 3-Server deployment and inspect the cold-start logs, then compare behavior when Stores register after the initial retry window. Done should mean a cold-start Server does not exit while Stores are still registering, with the failure cause diagnosable from container output.

Written by the indexing model from the issue text.

Assessment

Tech stack
docker, java, kubernetes
Domain
backend, databases, distributed-systems
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Active
Clarity
Mostly clear
Newbie friendliness
55/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.