# Two leaders in cluster after OutOfMemoryError

**URL:** <https://community.neo4j.com/t/two-leaders-in-cluster-after-outofmemoryerror/6873>\
**Category:** Operations\
**Created:** [April 24, 2019, 7:40pm UTC](https://community.neo4j.com/t/two-leaders-in-cluster-after-outofmemoryerror/6873 "2019-04-24T19:40:44Z")\
**Posts on this page:** 5\
**Page:** 1

<div class="post-metadata">

**Author:** ![wergeland](https://sea1.discourse-cdn.com/flex021/user_avatar/community.neo4j.com/wergeland/32/1080_2.png) [@wergeland](https://community.neo4j.com/u/wergeland)\
**Post date:** [April 24, 2019, 7:40pm UTC](https://community.neo4j.com/t/two-leaders-in-cluster-after-outofmemoryerror/6873/1 "2019-04-24T19:40:44Z")

</div>

We run a 3 node causal cluster in Kubernetes, enterprise 3.5.3 version, with the following cluster configuration:

```auto
HOSTNAME=$(hostname)
ID=${HOSTNAME#neo4jtest-}
export NEO4J_dbms_connectors_default __advertised__ address=10.132.2.${ID}
export NEO4J_causal __clustering_discovery__ advertised__address=$(hostname -f):5000
export NEO4J_causal __clustering_transaction__ advertised__address=10.132.2.${ID}:600
export NEO4J_causal __clustering_raft__ advertised__address=$(hostname -f):7000

```

We have also configured readiness and liveness probes:

```auto
        readinessProbe:
          initialDelaySeconds: 60
          httpGet:
            path: /db/manage/server/core/available
            port: 7474
        livenessProbe:
          initialDelaySeconds: 60
          httpGet:
            path: /db/manage/server/core/available
            port: 7474

```

Today we discovered that we had inconsistent data in our test environment.

We have tracked down the root cause to be that the leader node went `OutOfMemoryError` 12 days ago that lead to the node disabling Hazelcast. The two follower nodes formed a 2 node cluster and elected a new leader, but according to `:sysinfo` the old leader still believed it was the leader of a 3 node cluster with the two other nodes as followers. The debug log from the faulty node contains some statements that contradicts the `:sysinfo` output though:

```auto
2019-04-12 07:59:19.231+0000 ERROR [o.n.b.r.ExecutorBoltScheduler] Unexpected error during job scheduling for session 'bolt-94767'. java.lang.OutOfMemoryError: Java heap space
java.util.concurrent.CompletionException: java.lang.OutOfMemoryError: Java heap space
	at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:273)
	at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:280)
	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1592)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.OutOfMemoryError: Java heap space
2019-04-12 07:59:19.552+0000 ERROR [o.n.b.t.p.HouseKeeper] Fatal error occurred when handling a client connection: [id: 0x095bb3af, L:/10.48.4.33:7687 ! R:/10.132.0.39:59536] Java heap space
java.lang.OutOfMemoryError: Java heap space
2019-04-12 07:59:19.553+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=540646, gcTime=0, gcCount=0}
2019-04-12 07:59:19.553+0000 WARN [o.n.b.r.BoltConnectionReadLimiter] Channel [/127.0.0.1:48578]: consumed messages on the worker queue below 100, auto-read is being enabled.
2019-04-12 07:59:19.554+0000 INFO [o.n.c.c.c.s.RaftState] Leader changed from MemberId{b5353fdb} to null
2019-04-12 07:59:19.696+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=314, gcTime=224, gcCount=2}
2019-04-12 07:59:19.718+0000 WARN [o.n.b.r.BoltConnectionReadLimiter] Channel [/127.0.0.1:48578]: client produced 301 messages on the worker queue, auto-read is being disabled.
2019-04-12 07:59:19.719+0000 WARN [o.n.b.r.BoltConnectionReadLimiter] Channel [/127.0.0.1:48578]: consumed messages on the worker queue below 100, auto-read is being enabled.
2019-04-12 07:59:19.851+0000 INFO [o.n.c.c.c.s.RaftLogShipper] Stopping log shipper MemberId{3cf28095}[matchIndex: 1177136, lastSentIndex: 1177136, localAppendIndex: 1177136, mode: PIPELINE]
2019-04-12 07:59:19.851+0000 INFO [o.n.c.c.c.s.RaftLogShipper] Stopping log shipper MemberId{c0c80264}[matchIndex: 1177136, lastSentIndex: 1177136, localAppendIndex: 1177136, mode: PIPELINE]
2019-04-12 07:59:19.852+0000 INFO [o.n.c.c.c.m.RaftMembershipChanger] Inactive{}
2019-04-12 07:59:19.852+0000 INFO [o.n.c.c.r.RaftReplicator] Lost previous leader 'MemberId{b5353fdb}'. Currently no available leader
2019-04-12 07:59:19.852+0000 INFO [c.n.c.d.SslHazelcastCoreTopologyService] Step down event detected. This topology member, with MemberId MemberId{b5353fdb}, was leader in term 6481, now moving to follower.
2019-04-12 07:59:19.852+0000 INFO [c.n.c.d.SslHazelcastCoreTopologyService] Leader MemberId{b5353fdb} updating leader info for database default and term 6482
2019-04-12 07:59:19.853+0000 INFO [o.n.c.c.c.s.RaftState] First leader elected: MemberId{c0c80264}
2019-04-12 07:59:19.863+0000 INFO [o.n.c.c.r.RaftReplicator] A new leader has been detected: 'MemberId{c0c80264}'
2019-04-12 07:59:20.059+0000 WARN [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=116, gcTime=127, gcCount=1}
2019-04-12 07:59:20.090+0000 WARN [c.n.c.d.SslHazelcastCoreTopologyService] Uncaught exception Hazelcast instance is not active!
com.hazelcast.core.HazelcastInstanceNotActiveException: Hazelcast instance is not active!
	at com.hazelcast.spi.impl.operationservice.impl.InvocationRegistry.shutdown(InvocationRegistry.java:182)
	at com.hazelcast.spi.impl.operationservice.impl.OperationServiceImpl.shutdownInvocations(OperationServiceImpl.java:496)
	at com.hazelcast.spi.impl.NodeEngineImpl.shutdown(NodeEngineImpl.java:434)
	at com.hazelcast.instance.Node.shutdownServices(Node.java:456)
	at com.hazelcast.instance.Node.shutdown(Node.java:430)
	at com.hazelcast.instance.OutOfMemoryHandlerHelper.tryShutdown(OutOfMemoryHandlerHelper.java:61)
	at com.hazelcast.instance.DefaultOutOfMemoryHandler.onOutOfMemory(DefaultOutOfMemoryHandler.java:87)
	at com.hazelcast.instance.OutOfMemoryErrorDispatcher.onOutOfMemory(OutOfMemoryErrorDispatcher.java:189)
	at com.hazelcast.internal.partition.impl.MigrationThread.run(MigrationThread.java:66)
	at ------ submitted from ------.(Unknown Source)
	at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.resolve(InvocationFuture.java:111)
	at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.resolveAndThrow(InvocationFuture.java:74)
	at com.hazelcast.spi.impl.AbstractInvocationFuture.get(AbstractInvocationFuture.java:158)
	at com.hazelcast.multimap.impl.MultiMapProxySupport.invoke(MultiMapProxySupport.java:252)
	at com.hazelcast.multimap.impl.MultiMapProxySupport.getAllInternal(MultiMapProxySupport.java:77)
	at com.hazelcast.multimap.impl.ObjectMultiMapProxy.get(ObjectMultiMapProxy.java:115)
	at org.neo4j.causalclustering.discovery.HazelcastClusterTopology.toCoreMemberMap(HazelcastClusterTopology.java:356)
	at org.neo4j.causalclustering.discovery.HazelcastClusterTopology.getCoreTopology(HazelcastClusterTopology.java:105)
	at org.neo4j.causalclustering.discovery.HazelcastCoreTopologyService.refreshCoreTopology(HazelcastCoreTopologyService.java:385)
	at org.neo4j.causalclustering.discovery.HazelcastCoreTopologyService.refreshTopology(HazelcastCoreTopologyService.java:375)
	at org.neo4j.causalclustering.helper.RobustJobSchedulerWrapper.withErrorHandling(RobustJobSchedulerWrapper.java:51)
	at org.neo4j.causalclustering.helper.RobustJobSchedulerWrapper.lambda$scheduleRecurring$1(RobustJobSchedulerWrapper.java:41)
	at org.neo4j.kernel.impl.scheduler.ScheduledJobHandle.lambda$new$0(ScheduledJobHandle.java:83)
	at org.neo4j.kernel.impl.scheduler.ThreadPool.lambda$submit$0(ThreadPool.java:57)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
2019-04-12 07:59:20.799+0000 WARN [o.n.k.i.p.Procedures] Error during iterate.commit:
2019-04-12 07:59:20.800+0000 WARN [o.n.k.i.p.Procedures] 1 times: java.lang.NullPointerException

```

The other two nodes logged:

```auto
2019-04-12 13:49:12.712+0000 INFO [o.n.c.m.RaftOutbound] No address found for MemberId{b5353fdb}, probably because the member has been shut down.

```

Also note that `http://localhost:7474/db/manage/server/core/available` must have returned OK on the faulty node, otherwise Kubernetes would have restarted it.

`Last Tx Id` was `300980` on the original leader, and `596152` on the other two nodes. After restarting the old leader node, it managed to join the cluster and sync up.

As far as we were able to see from the timestamps in the debug output from the `DiagnonsticsManager`, the original leader had not received any writes after the `OutOfMemoryError`, but we don't know how we can confirm that. Would a write to the old leader end up in an error when propagating the write to the new leader?

We are a bit scared that the cluster got into this state. As far as we have experienced with some large queries and updates, Neo4j tries to handle OutOfMemoryError, but in this case it looks like Hazelcast's shutdown handler was invoked. According to the release notes of 3.4, it was disabled in 3.4.0-alpha09, but it is obviously active in 3.5.3.

How can this scenario be prevented? It looks like the only safe thing to do is always restart a Neo4j node if `OutOfMemoryError` occurs.

Complete `debug.log` from the faulty node can be provided on request.

---

<div class="post-metadata">

**Author:** ![andrew\_bowman](https://sea1.discourse-cdn.com/flex021/user_avatar/community.neo4j.com/andrew_bowman/32/73_2.png) [@andrew\_bowman](https://community.neo4j.com/u/andrew_bowman)\
**Post date:** [April 25, 2019, 12:24am UTC](https://community.neo4j.com/t/two-leaders-in-cluster-after-outofmemoryerror/6873/2 "2019-04-25T00:24:58Z")

</div>

Due to the nature of causal clustering, notably quorum commits, a transaction can only commit when the majority of the cluster can also commit. Even in the event that the old leader could still contact the other members of the cluster, the term for the commit would be older than the term being used for the 2-node cluster after the new leader was elected, and would be rejected.

In other words, a single isolated node in the cluster, even if it thinks it's the leader, has no ability to commit any transactions that could go to it, since quorum consensus for the latest leadership term is required for that to happen.

And yes after an OutOfMemoryException restarting is the best way forward.

I'll see if engineering can take a glance and offer any additional comments.

---

<div class="post-metadata">

**Author:** ![wergeland](https://sea1.discourse-cdn.com/flex021/user_avatar/community.neo4j.com/wergeland/32/1080_2.png) [@wergeland](https://community.neo4j.com/u/wergeland)\
**Post date:** [April 25, 2019, 8:08am UTC](https://community.neo4j.com/t/two-leaders-in-cluster-after-outofmemoryerror/6873/3 "2019-04-25T08:08:24Z")

</div>

Thank you very much for the swift reply. It is reassuring that the faulty leader would not have succeeded any commits. We will take steps to monitor for `OutOfMemoryError`.

By the way, we have set environment variable `NUMBER_OF_CORES` to 3 in Kubernetes, per various tutorials and examples, but we cannot find any reference documentation for this.

We have _not_ set `NEO4J_causal __clustering_minimum__ core __cluster__ size __at__ runtime`, which per documentation defaults to 3, but the 2 remaining nodes formed an operational writeable cluster. This is how we would like the cluster to behave (as 2 still is majority of 3), but I would feel more confident if I knew how the default of 3 is overridden.

I am looking forward to hear from engineering why Hazelcast shut down on the faulty node.

---

<div class="post-metadata">

**Author:** ![andrew\_bowman](https://sea1.discourse-cdn.com/flex021/user_avatar/community.neo4j.com/andrew_bowman/32/73_2.png) [@andrew\_bowman](https://community.neo4j.com/u/andrew_bowman)\
**Post date:** [April 25, 2019, 10:23am UTC](https://community.neo4j.com/t/two-leaders-in-cluster-after-outofmemoryerror/6873/4 "2019-04-25T10:23:55Z")

</div>

The defaults for the min core cluster size at runtime should be fine.

This is a bit of a confusing topic, but I'll try to summarize.

In causal clusters, you can think of cluster membership like a VIP list, and only cluster members are allowed to take part in consensus operations, like commits. The number of members on the list is used to calculate majority quorum (for 3 members, majority is 2...for 4 or 5 members, majority is 3, etc). It is possible for a node to be a cluster member, but be unreachable or offline, and it still counts as a cluster member when it comes to calculating the majority.

The membership list can increase or decrease as members are added and removed. The thing to remember is that **the voting in or out of members requires a majority quorum vote to succeed**.

So if you have a 3-node cluster and another node is added, a majority (2) is needed to vote to add that member to the membership list and be counted as a cluster member (and the majority number will be updated to 3). If a member becomes unreachable or shuts down, even though it may be unreachable, a vote must take place first to remove that node's cluster membership, so 3 nodes must be online and able to vote out the member (and the cluster size would decrease to 3, majority becomes 2).

The minimum core cluster size at runtime (default 3) means the membership list cannot shrink below 3 members. If one node of the 3-node cluster leaves or is unreachable, there will not be a vote to remove the member since that would lower the cluster members below the minimum. Therefore the node that left is still counted as a cluster member, even if it is offline.

This is also why when you lose quorum (for example 2 out of 3 cluster members offline) that the only way to regain quorum is to bring back one of those offline members. You cannot add a brand new node to the cluster to recover, as quorum is required to vote in new cluster members.

And just to note, that is all by design in the Raft protocol, as this behavior is critical to maintaining data durability in the cluster. If we allowed brand new cluster members to be added even when we have lost quorum, although it would be a very fast way to regain write capability, it would risk scenarios that can result in losing previous commits to the database.

---

<div class="post-metadata">

**Author:** ![wergeland](https://sea1.discourse-cdn.com/flex021/user_avatar/community.neo4j.com/wergeland/32/1080_2.png) [@wergeland](https://community.neo4j.com/u/wergeland)\
**Post date:** [April 25, 2019, 10:56am UTC](https://community.neo4j.com/t/two-leaders-in-cluster-after-outofmemoryerror/6873/5 "2019-04-25T10:56:44Z")

</div>

Thank your for the clarification! I understand that I mixed _cluster size_ and _quorum majority_ when reading the documentation here.

We will leave the settings to default. 🙂
