Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Index Data Loss After Rolling Update #13456

Closed
LukasVyhlidka opened this issue Jul 17, 2018 · 11 comments
Closed

Index Data Loss After Rolling Update #13456

LukasVyhlidka opened this issue Jul 17, 2018 · 11 comments

Comments

@LukasVyhlidka
Copy link
Contributor

@LukasVyhlidka LukasVyhlidka commented Jul 17, 2018

Hi guys, we've ran into a serious issue. We've been trying to solve it ourselves for quite long time without a success so we decided to ask for a little help with the investigation and possibly with the solution as well.

Our problematic infrastructure is consisted of two nodes with the embedded Hazelcast (cluster of two). We're using the IMap collection that is loaded initially by a Map Loader. After the initial load is done the data are altered programmatically - put operations on the IMap and so on. To query the data stored in the IMap we're using the Predicates.

The issue occurs when we do a rolling update of the application - first instance is turned off, updated and after it is done the second instance takes place. After such a rolling update (without the downtime) we can see that apx. 40 % of the data are lost.

Actually the data are not lost completely - they are stored in the map itself. Unfortunately in case we query the map using the Predicate that uses the index not all the data are returned. We suppose that the index gets corrupted somehow, unfortunately we was not able to figure out why...

Here is the configuration of the map:

<hz:map name="marketplaceLoans" in-memory-format="OBJECT">
    <hz:map-store enabled="true" write-delay-seconds="0" implementation="marketplaceLoansMapLoader"/>
    <hz:indexes>
        <hz:index attribute="datePublished" ordered="true"/>
        <hz:index attribute="interestRate" ordered="true"/>
        <hz:index attribute="covered" ordered="false"/>
        <hz:index attribute="termInMonths" ordered="true"/>
        <hz:index attribute="purpose" ordered="true"/>
        <hz:index attribute="rating" ordered="true"/>
        <hz:index attribute="topped" ordered="false"/>
        <hz:index attribute="remainingInvestment" ordered="true"/>
        <hz:index attribute="repaymentPeriodCategory" ordered="true"/>
        <hz:index attribute="investments[any].investorId" ordered="true"/>
        <hz:index attribute="insuranceActive" ordered="false"/>
    </hz:indexes>
</hz:map>

And here an info about SW:

  • Hazelcast 3.10.1
  • Cluster Size - 2 nodes
  • Java: Java(TM) SE Runtime Environment (build 1.8.0_161-b12)
  • OS: Ubuntu 16.04.4 LTS (Xenial Xerus), kernel 4.4.0-116-generic
@LukasVyhlidka
Copy link
Contributor Author

@LukasVyhlidka LukasVyhlidka commented Jul 18, 2018

Hi guys, after another day of investigation a colleague of mine (@tomix26) figured out the problem. After the Split Brain of nodes the index gets corrupted. Here is the test that shows the problem. If you run it the last assertion in onAfterSplitBrainHealed method fails.

The issue is a regression because it works in version 3.9.4.

package net.homecredit.p2p.rest;

import com.hazelcast.config.Config;
import com.hazelcast.config.MapConfig;
import com.hazelcast.config.MapIndexConfig;
import com.hazelcast.core.HazelcastInstance;
import com.hazelcast.query.Predicates;
import com.hazelcast.test.HazelcastParallelClassRunner;
import com.hazelcast.test.SplitBrainTestSupport;
import org.junit.runner.RunWith;

import java.io.Serializable;
import java.util.Arrays;
import java.util.List;
import java.util.concurrent.ThreadLocalRandom;

import static org.junit.Assert.assertEquals;

@RunWith(HazelcastParallelClassRunner.class)
public class IndexAwarePredicateSplitBrainTest extends SplitBrainTestSupport {

    private static final List<String> POSSIBLE_VALUES = Arrays.asList("A", "B", "C", "D");

    @Override
    protected int[] brains() {
        return new int[] { 1, 2 };
    }

    @Override
    protected Config config() {
        return super.config().addMapConfig(new MapConfig()
                .setName("test")
                .addMapIndexConfig(new MapIndexConfig()
                        .setAttribute("value").setOrdered(true)));
    }

    @Override
    protected void onBeforeSplitBrainCreated(HazelcastInstance[] instances) {
        for (long key = 0; key < 10000; key++) {
            String randomValue = POSSIBLE_VALUES.get(ThreadLocalRandom.current().nextInt(POSSIBLE_VALUES.size()));
            instances[0].getMap("test").put(key, new TestObject(key, randomValue));
        }

        for (HazelcastInstance instance : instances) {
            assertEqualsEventually(() -> instance.getMap("test").size(), 10000);
            assertEquals(10000, instance.getMap("test").keySet(Predicates.not(Predicates.equal("value", "X"))).size());
            assertEquals(10000, instance.getMap("test").keySet(Predicates.in("value", "A", "B", "C", "D")).size());
        }
    }

    @Override
    protected void onAfterSplitBrainHealed(HazelcastInstance[] instances) {
        for (HazelcastInstance instance : instances) {
            assertEqualsEventually(() -> instance.getMap("test").size(), 10000);
            assertEquals(10000, instance.getMap("test").keySet(Predicates.not(Predicates.equal("value", "X"))).size());
            assertEquals(10000, instance.getMap("test").keySet(Predicates.in("value", "A", "B", "C", "D")).size());
        }
    }

    private static class TestObject implements Serializable {

        private Long id;
        private String value;

        public TestObject() {}

        public TestObject(Long id, String value) {
            this.id = id;
            this.value = value;
        }

        public Long getId() {
            return id;
        }

        public void setId(Long id) {
            this.id = id;
        }

        public String getValue() {
            return value;
        }

        public void setValue(String value) {
            this.value = value;
        }
    }
}
@mdogan
Copy link
Contributor

@mdogan mdogan commented Jul 18, 2018

Thanks for the report and test @LukasVyhlidka.

@mdogan
Copy link
Contributor

@mdogan mdogan commented Jul 18, 2018

Issue is in new split-brain handler mechanism introduces in 3.10.

While split-brain merge process is running, only data in local partitions are merged and non-local ones are disposed.
See AbstractSplitBrainHandlerService.StoreCollector.asyncDestroyStores(..) -> AbstractSplitBrainHandlerService.destroyStore(store) -> RecordStore.destroyInternals().
This is to release memory (especially native) consumed by record storage and also clear previous indexes.

During merge process, indexes are created when migration is committed on destination node (when replica-index = 0). But since merge process is executed concurrently with migrations, when indexes are global (in-memory format is not native), it can happen that RecordStore.destroyInternals() removes valid indexes from global indexes accidentally.

@mdogan mdogan modified the milestones: 3.11, 3.10.4 Jul 18, 2018
@taburet
Copy link
Contributor

@taburet taburet commented Jul 18, 2018

@LukasVyhlidka from which Hazelcast version you were updating the cluster when you faced the initial rolling update issue?

@taburet
Copy link
Contributor

@taburet taburet commented Jul 18, 2018

@LukasVyhlidka seems like I got you wrong, you were not upgrading Hazelcast from one version to another, you were just updating your application code, right?

@LukasVyhlidka
Copy link
Contributor Author

@LukasVyhlidka LukasVyhlidka commented Jul 19, 2018

@taburet as you said. We just updated the app code. Hazelcast was in the same version all the time. Provided Unit test should show the problem - it runs on one version of the Hazelcast and validates the SplitBrain recovery.

@mmedenjak
Copy link
Contributor

@mmedenjak mmedenjak commented Jul 19, 2018

@LukasVyhlidka thank you again for sharing the reproducer. It definitely helps find the root cause.
But we would also like to understand how your application started split brain recovery, which is not usual when shutting down and restarting instances.
Can you share your logs on all instances from when you restart nodes?

@tomix26
Copy link

@tomix26 tomix26 commented Jul 20, 2018

@mmedenjak here is the log file: splunk_export.txt

It's an export from Splunk, so the most recent events are on the top.

I also attach our configuration of the cluster that could be related to the split brain issue:

<hz:properties>
    <hz:property name="hazelcast.operation.thread.count">32</hz:property>
    <hz:property name="hazelcast.slow.operation.detector.threshold.millis">1000</hz:property>
    <hz:property name="hazelcast.slow.operation.detector.stacktrace.logging.enabled">true</hz:property>
    <hz:property name="hazelcast.client.invocation.timeout.seconds">60</hz:property>
    <hz:property name="hazelcast.heartbeat.interval.seconds">1</hz:property>
    <hz:property name="hazelcast.heartbeat.failuredetector.type">phi-accrual</hz:property>
    <hz:property name="hazelcast.heartbeat.phiaccrual.failuredetector.threshold">7</hz:property>
    <hz:property name="hazelcast.max.no.heartbeat.seconds">10</hz:property>
    <hz:property name="hazelcast.shutdownhook.policy">GRACEFUL</hz:property>
    <hz:property name="hazelcast.logging.type">slf4j</hz:property>
</hz:properties>
@mmedenjak
Copy link
Contributor

@mmedenjak mmedenjak commented Jul 23, 2018

Closing as issue has been fixed and the fix will be released with 3.10.4 in about a weeks time.

@mmedenjak mmedenjak closed this Jul 23, 2018
@mustafaiman
Copy link
Contributor

@mustafaiman mustafaiman commented Aug 2, 2018

failed in PR builder https://hazelcast-l337.ci.cloudbees.com/job/Hazelcast-EE-pr-builder/4105/

java.lang.AssertionError: expected:<10000> but was:<8294>
	at org.junit.Assert.fail(Assert.java:88)
	at org.junit.Assert.failNotEquals(Assert.java:834)
	at org.junit.Assert.assertEquals(Assert.java:645)
	at org.junit.Assert.assertEquals(Assert.java:631)
	at com.hazelcast.map.merge.NoIndexLossAfterSplitBrainHealTest.onAfterSplitBrainHealed(NoIndexLossAfterSplitBrainHealTest.java:102)
	at com.hazelcast.test.SplitBrainTestSupport.doIteration(SplitBrainTestSupport.java:222)
	at com.hazelcast.test.SplitBrainTestSupport.testSplitBrain(SplitBrainTestSupport.java:210)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:106)
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:98)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.lang.Thread.run(Thread.java:748)
@ahmetmircik
Copy link
Member

@ahmetmircik ahmetmircik commented Sep 11, 2018

should be fixed by #13653

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

8 participants
You can’t perform that action at this time.