Indexes not persisted

[folch]

Hello,

I'm trying to setup a cluster (2 nodes) with Modeshape 4.4.0 and using indexes.

The cluster works fine and indexes are updated in both nodes properly. However, I'm trying to see what happens when one of the cluster nodes is shutdown.

The situation is the following:

* Node1 and Node2 started.

* Adding 3 documents on Node1. Cluster works and we can see 3 documentos on both nodes.

* Stop Node2.

* Adding 2 documents on Node1.

* Start Node2. 

• If I search using the defined indexes, in Node1 I can see 5 documents. In Node2 I can see 3 documents.
• If I search without using any index. In both nodes I can see 5 documents.

* I use Workspace.reindex() method to forze a manuall reindex in Node2. After the reindex, I can see 5 documents searching using the index in Node2. So everthing is ok.

* I restart Node2 and I can see only 3 documents. Seems that manual reindex operation was not persisted. I need to reindex manually again.

Then, 2 questions:

a) Is there any other mechanism available in Modeshape 4.4.0 to re-synchronize indexes in a cluster? If I'm not wrong "reindex" and "partial reindex" config settings will be available in Modeshape 4.5.0 and reindex from a specific date/time is not available yet. Please correct me if I'm wrong.

b) Am I missing something when calling Workspace.reindex() operation? Any config setting somewhere...

Attached you can find my modeshape configs.

Thanks in advance

[hchiorean]

a) Is there any other mechanism available in Modeshape 4.4.0 to re-synchronize indexes in a cluster? If I'm not wrong "reindex" and "partial reindex" config settings will be available in Modeshape 4.5.0 and reindex from a specific date/time is not available yet. Please correct me if I'm wrong.

There is no way to automagically sync indexes in a cluster in ModeShape 4.4. You're correct, in ModeShape 4.5 we've added a new "incremental" indexing capability which should work if you enable the event journal.

b) Am I missing something when calling Workspace.reindex() operation? Any config setting somewhere...

Unless there's a bug somewhere, if a reindex() operation completes successfully and data is retrieved correctly from the indexes, that means that those indexes have been brought up-to-date. I don't see why shutting down and restarting again would loose indexed information.

You should investigate/debug this in your environment and if you can spot the problem, feel free to raise a JIRA (just remember we need to be able to reproduce the issue locally in order to fix it).

EDIT: I think I know where the bug is: the local index provider is not committing changes to MapDB after a reindexing operation, meaning that the changes are held only in memory, never persisted. I'll investigate this some more and if this is correct, I'll open a JIRA for 4.5.0.Final.

[hchiorean]

Looked at the code in 4.4.0.Final a bit and if the repository is shutdown correctly (via the repository shutdown method) data in the index providers is committed. Are you shutting down your repositories correctly or are you killing the VMs ? If the latter, it's probably the main cause why data is not persisted after a "reindexing" operation. If that's the case, you need to make sure for 4.4.0.Final you're calling the repository.shutdown() method.

[hchiorean]

See [MODE-2517] Index providers should commit changes to indexes after a reindexing operation - JBoss Issue Tracker (and also the workarounds for 4.4.0.Final)

[folch]

Hi Horia,

Thanks for your answer, I'll repeat the test ensuring I'm doing a proper shutdown.

However, I cannot find a method shutdown in Repository object. This is what we are doing:

  public void unregister(Repository repository, ModeShapeEngine engine) {

        try {

            Map<String, ModeShapeEngine.State> repos = engine.getRepositories();

            Future<Boolean> future;

            for (String repoName:repos.keySet()) {

                future = engine.undeploy(repoName);

                future.get();

            }

            boolean engineDown = false;

            int numTries = 1;

            while (!engineDown && numTries<6) {

                future = engine.shutdown(false);

                numTries++;

                if (future.get()) {

                    Log.info("Engine shutdown completed");

                    engineDown = true;

                } else {

                    Thread.sleep(5000); // Wait 5s and .

                    Log.info("At least one repository is in use, Waiting 5s.");

                }

            }

            if (!engineDown) {

                Log.info("Forcing the shutting down of the engine.");

                future = engine.shutdown(true);

                if (future.get()) {

                    Log.info("Forced engine shutdown completed");

                } else {

                    Log.error("Forced engine shutdown not completed");

                }

            }

        }  catch (NoSuchRepositoryException e) {

            Log.error("Repository not found", e.getMessage());

        } catch (InterruptedException e) {

            Log.warn(LogMessages.REPO_STOP_EXCEPTION, e.getMessage());

        } catch (ExecutionException e) {

            Log.error(LogMessages.REPO_STOP_EXCEPTION, e.getMessage());

        }

  }

Is it a proper way to shutdown Modeshape/Infinispan? We are embeding Modesahpe in an Application Server (TomEE, Websphere or Weblogic).

Thanks

[hchiorean]

future = engine.undeploy(repoName) will shutdown a particular repository, so there isn't anything else required. Are you doing this in your test when you're restarting Node 2 ?

[folch]

Usually I do a clean TomEE shutdown, however I cannot warranty that in all the cases I did a shutdown or simply I closed TomEE.

I will check it again. In any case, as a non-planned shutdown is always possible, I will implement second workaround also.

I really appreciate your help.

[folch]

I've repeated the test, ensuring that Modeshape Repository of Node 2 is always properly shutdown. And I can confirm that the errror does not happen in that case.

In any case, I will do the second workaround to avoid problems in case of non-planned shutdowns.

However, I've seen a lot of this traces in Catalina error log when I try to shutdown my application.

Oct 30, 2015 1:00:30 PM org.apache.catalina.loader.WebappClassLoader checkThreadLocalMapForLeaks

SEVERE: The web application [/hes] created a ThreadLocal with key of type [org.jboss.marshalling.UTFUtils.BytesHolder] (value [org.jboss.marshalling.UTFUtils$BytesHolder@5e166dae]) and a value of type [byte[]] (value [[B@127aeac4]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.

Oct 30, 2015 1:00:30 PM org.apache.catalina.loader.WebappClassLoader checkThreadLocalMapForLeaks

SEVERE: The web application [/hes] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@43caf356]) and a value of type [org.infinispan.commons.util.concurrent.jdk8backported.BoundedEquivalentConcurrentHashMapV8.CounterHashCode] (value [org.infinispan.commons.util.concurrent.jdk8backported.BoundedEquivalentConcurrentHashMapV8$CounterHashCode@412db5df]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.

Oct 30, 2015 1:00:30 PM org.apache.catalina.loader.WebappClassLoader checkThreadLocalMapForLeaks

SEVERE: The web application [/hes] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@1fff64e7]) and a value of type [org.infinispan.commons.util.concurrent.jdk8backported.EquivalentConcurrentHashMapV8.CounterHashCode] (value [org.infinispan.commons.util.concurrent.jdk8backported.EquivalentConcurrentHashMapV8$CounterHashCode@38398a1a]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.

Oct 30, 2015 1:00:30 PM org.apache.catalina.loader.WebappClassLoader checkThreadLocalMapForLeaks

SEVERE: The web application [/hes] created a ThreadLocal with key of type [org.modeshape.jcr.NodeTypes$1] (value [org.modeshape.jcr.NodeTypes$1@4999cdcc]) and a value of type [org.modeshape.jcr.NodeTypes.SingleNodeDefinitionSet] (value [org.modeshape.jcr.NodeTypes$SingleNodeDefinitionSet@23df1f34]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.

Have you seen it before? Seems that something in Infinispan has not been properly shutdown.

Update Note: I've seen this Infinispan bug [ISPN-2786] ThreadLocal memory leak in Tomcat - JBoss Issue Tracker

Seems that is the same issue. Do you have any updated info on that? Should I raise a question in Infinispan forum?

[hchiorean]

No, I've not seen these stack traces before, but it seems to be related to Tomcat/CLs and GC: http://stackoverflow.com/questions/7788280/memory-leak-when-redeploying-application-in-tomcat

Until 4.5.0.Final (for which the above mentioned JIRA will be fixed) is out, you can try registering a shutdown hook in your JVM which shuts the repo down. This won't cover all possible VM shutdown cases (e.g. kill -09) but it's better than nothing.

[hchiorean]

Update Note: I've seen this Infinispan bug [ISPN-2786] ThreadLocal memory leak in Tomcat - JBoss Issue Tracker

Seems that is the same issue. Do you have any updated info on that? Should I raise a question in Infinispan forum?

Yes, for any ISPN related issue you should contact the Infinispan community.

[folch]

Thanks,

Adding a link to Infinispan forum question, for trackin purposes.Tomcat shutdown Thread leaks detected