Skip to content

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

Description

@bitflicker64

Bug Type (问题类型)

server status (启动/运行异常)

Before submit

  • 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

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 /
#3132, but it is a workaround for the retry ceiling, not a fix for it.

Related

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

Not applicable, the cluster is empty.

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

Not applicable, the failure happens before any schema exists.

Activity

  1. SebastianGruza commented on Sep 12, 2026

    @SebastianGruza
    Contributor

    Reproduced outside Kubernetes, same outcome

    I reproduced this on 3 VMs (1 PD + 3 Store + 1 Server, tarball built from master 60c8803, no Docker) by starting the Server right after PD and delaying the Store registration by a fixed number of seconds. The results are deterministic:

    Server config stores register (after PD) result
    usePD=true, first boot of the cluster 1 store at +5 s, the other two at +71 s 10 attempts in 38 s (sleeps 1,1,1,2,3,4,5,6,7,8 s), upper limit : 10, exit 1
    usePD=true, first boot of the cluster 1 store at +5 s, the other two at +26 s 9 attempts, the 9th succeeds, Server starts
    local conf/graphs, no usePD all stores at +20 / +45 / +60 s Server up after 8 s, no error 105 at all; the missing stores only show up as code 102 in the task-db-worker thread

    With zero registered stores PD answers 102 (There is no any online store), with one or two it answers 105; the client treats both the same way.

    Script and logs: cluster/repro_coldstart.sh, results/issue-3203/.

    What the partition lookup on the main thread actually is

    The path that ends in NodeTxSessionProxy.createTable is the creation of the system graph DEFAULT-~sys_graph: GraphManager.loadMetaFromPD → kvStoreInit → createSysGraphIfNeed. That method calls createGraph(..., init = true) only when PD holds no system-graph config yet, and initBackend() on hstore is HstoreStore.init → createTable, i.e. the first partition lookup. This explains both observations at once: it can only happen on the very first boot of a cluster, and never on pod replacement, because by then the config is in PD and init is false. The trigger is usePD=true in rest-server.properties, which the entrypoint sets from HG_SERVER_USE_PD.

    Two small corrections to the "Related" section: init-store is not involved here, it skips hstore graphs since b9a3dd9; and on the PD side code 105 comes from StoreNodeService.allocShards and is thrown only while the shard group of a partition does not exist yet, so also only on a cold cluster.

    Stdout

    Confirmed: without STDOUT_MODE=true, hugegraph-server.sh redirects the JVM's stdout and stderr to logs/hugegraph-server-stdout.log, and the image's entrypoint does not enable that mode. All that reaches docker logs is the line from start-hugegraph.sh.

    Direction I would consider for a fix

    • Since this is a one-off bootstrap path, a gate "wait until PD reports at least minStoreCount active stores" right before createSysGraphIfNeed (or in HstoreSessionsImpl.open), with a configurable timeout and a log line every few seconds. PDClient.getActiveStores() and getPDConfig() already expose what is needed.
    • I would not change NODE_MAX_RETRYING_TIMES or the general retry loop for this: the same counter handles failures during normal operation, and fix(store-client): enhance thread interrupts in NodeTxExecutor #3204 touches that loop right now; two PRs changing its semantics at the same time would be hard to review.
    • STDOUT_MODE=true in the image's entrypoint as a separate one-line change.

    If you want, I can try to implement such a gate with a test and measure it with the same script; if you would rather do it yourself, I am happy to test your patch against the same reproduction.

  2. SebastianGruza commented on Sep 16, 2026

    @SebastianGruza
    Contributor

    Server-side fix in #3210: with usePD=true, GraphManager waits for pd.initial-store-count active stores in PD before it opens the first hstore graph, bounded by a new option pd.stores_wait_timeout (default 300 s, 0 restores today's behaviour). Measured on the same reproduction as above (1 PD + 3 Store + 1 Server from a tarball, stores registering +5 s and +71 s after PD, usePD=true, first boot):

    server result
    master 1a15e762 18 × error code = 105, backoff 1,1,1,2,3,4,5,6,7,8, upper limit : 10, exit 1 after 38 s
    1a15e762 + #3210 PD needs 3 active store(s) … waiting up to 300s, 14 progress lines (0/3 → 1/3 → 3/3), 3 active store(s) in PD after 70s, 0 × 105, exit 0 after 81 s, REST 200
    + #3210, pd.stores_wait_timeout=20, stores at +120 s 5 progress lines, then Timed out after 20s waiting for 3 active store(s) in PD (0 registered); start the stores first or raise pd.stores_wait_timeout, exit 1 after 31 s

    Two things from the measurement. The wait has to sit before any graph is opened, not only before the system graph is created: with a local conf/graphs hstore graph, that local graph is the first to hit the 10-retry ceiling. And getPDConfig() does not send min_store_count (ConfigService builds the response from partition_count and shard_count only), so the server takes shard_count; on a cluster where pd.initial-store-count differs from the replica count PD should fill that field, a one-line follow-up on the PD side. Logs and script: results/issue-3203/fix/ in https://github.com/SebastianGruza/hugegraph-validation. The [wait-storage] gate from #3132 stays the right thing for images; this change covers the tarball and any start without an orchestrator.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions