AEM 6.2 Mongo replica sets auto-fail-over do not work

Question

After Installing AEM-author and Mongo replica sets seemed to work well. My installed AEM version is 6.2

so I tried to check auto fail over capability by following methods. 1. stop mongod instance which is current Primary 2. check whether Secondary become Primary by issuing rs.status() mongo command 3. and check logs/error.log of AEM-author

Mongo replica sets seemed to correctly fail over. But AEM-author was broken with displaying following error.

/home/vagrant/mounts/author1/aem/22_crx-quickstart/logs/error__5.log:01.11.2016 12:36:06.386 *ERROR* [pool-44-thread-1] org.apache.sling.serviceusermapping.impl.ServiceUserMapperImpl cannot unregister ServiceUserMapped Mapping [serviceName=com.adobe.cq.social.cq-social-messaging, subServiceName=utility-reader, userName=communities-utility-reader]
/home/vagrant/mounts/author1/aem/22_crx-quickstart/logs/error__5.log:01.11.2016 12:36:06.386 *ERROR* [pool-44-thread-1] org.apache.sling.serviceusermapping.impl.ServiceUserMapperImpl cannot unregister ServiceUserMapped Mapping [serviceName=com.adobe.cq.social.cq-social-messaging, subServiceName=acl-manager, userName=communities-acl-manager]
/home/vagrant/mounts/author1/aem/22_crx-quickstart/logs/error__5.log:01.11.2016 12:36:06.964 *ERROR* [FelixDispatchQueue] org.apache.felix.http.jetty FrameworkEvent ERROR (org.osgi.framework.BundleException: Activator stop error in bundle org.apache.felix.http.jetty [36].)
/home/vagrant/mounts/author1/aem/22_crx-quickstart/logs/error_6.log:01.11.2016 13:27:59.516 *ERROR* [DocumentDiscoveryLiteService-BackgroundWorker-[2]] org.apache.jackrabbit.oak.plugins.document.DocumentDiscoveryLiteService doRun: got an exception: com.mongodb.MongoTimeoutException: Timed out after 10000 ms while waiting for a server that matches {serverSelectors=[ReadPreferenceServerSelector{readPreference=primary}, LatencyMinimizingServerSelector{acceptableLatencyDifference=15 ms}]}. Client view of cluster state is {type=ReplicaSet, servers=[{address=172.18.8.248:27017, type=ReplicaSetArbiter, averageLatency=1.0 ms, state=Connected}, {address=SERVW0014:27017, type=Unknown, state=Connecting, exception={com.mongodb.MongoException$Network: Exception opening the socket}, caused by {java.net.SocketException: Connection reset}}, {address=SERVW0015:27017, type=ReplicaSetSecondary, averageLatency=1.3 ms, state=Connected}]
/home/vagrant/mounts/author1/aem/22_crx-quickstart/logs/error_6.log:01.11.2016 13:29:46.343 *ERROR* [DocumentNodeStore background read thread (2)] org.apache.jackrabbit.oak.plugins.document.ClusterNodeInfo This oak instance failed to update the lease in time and can therefore no longer access this DocumentNodeStore. (leaseEndTime: 1477974601170, leaseTime: 120000, leaseFailureMargin: 20000, lease check end time (leaseEndTime-leaseFailureMargin): 1477974581170, now: 1477974585328, remaining: -4158) Need to stop oak-core/DocumentNodeStoreService.
/home/vagrant/mounts/author1/aem/22_crx-quickstart/logs/error_6.log:01.11.2016 13:29:46.343 *ERROR* [LeaseFailureHandler-Thread] org.apache.jackrabbit.oak.plugins.document.DocumentNodeStoreService handleLeaseFailure: stopping oak-core...
/home/vagrant/mounts/author1/aem/22_crx-quickstart/logs/error_6.log:01.11.2016 13:29:46.422 *ERROR* [LeaseFailureHandler-Thread] org.apache.jackrabbit.oak.plugins.document.ClusterNodeInfo This oak instance failed to update the lease in time and can therefore no longer access this DocumentNodeStore.
/home/vagrant/mounts/author1/aem/22_crx-quickstart/logs/error_6.log:01.11.2016 13:29:46.422 *ERROR* [LeaseFailureHandler-Thread] org.apache.sling.discovery.oak [org.apache.sling.discovery.oak.OakDiscoveryService(256)] The updatedPropertyProvider method has thrown an exception (com.google.common.util.concurrent.ExecutionError: java.lang.AssertionError: This oak instance failed to update the lease in time and can therefore no longer access this DocumentNodeStore.)
/home/vagrant/mounts/author1/aem/22_crx-quickstart/logs/error_6.log:01.11.2016 13:29:46.453 *ERROR* [LeaseFailureHandler-Thread] org.apache.jackrabbit.oak.plugins.document.ClusterNodeInfo This oak instance failed to update the lease in time and can therefore no longer access this DocumentNodeStore.
/home/vagrant/mounts/author1/aem/22_crx-quickstart/logs/error_6.log:01.11.2016 13:29:46.453 *ERROR* [LeaseFailureHandler-Thread] com.adobe.cq.social.cq-social-scf-impl [com.adobe.cq.social.scf.impl.SocialComponentFactoryManagerImpl(2527)] The unbindFactories method has thrown an exception (com.google.common.util.concurrent.ExecutionError: java.lang.AssertionError: This oak instance failed to update the lease in time and can therefore no longer access this DocumentNodeStore.)
/home/vagrant/mounts/author1/aem/22_crx-quickstart/logs/error_6.log:01.11.2016 13:29:46.500 *ERROR* [LeaseFailureHandler-Thread] org.apache.jackrabbit.oak.plugins.document.ClusterNodeInfo This oak instance failed to update the lease in time and can therefore no longer access this DocumentNodeStore.
/home/vagrant/mounts/author1/aem/22_crx-quickstart/logs/error_6.log:01.11.2016 13:29:46.500 *ERROR* [LeaseFailureHandler-Thread] com.adobe.cq.dtm.impl.DTMJobsInitializer Could not obtain a resource resolver.
/home/vagrant/mounts/author1/aem/22_crx-quickstart/logs/error_6.log:01.11.2016 13:29:46.625 *ERROR* [LeaseFailureHandler-Thread] org.apache.jackrabbit.oak.plugins.document.ClusterNodeInfo This oak instance failed to update the lease in time and can therefore no longer access this DocumentNodeStore.
/home/vagrant/mounts/author1/aem/22_crx-quickstart/logs/error_6.log:01.11.2016 13:29:46.625 *ERROR* [LeaseFailureHandler-Thread] org.apache.sling.discovery.oak [org.apache.sling.discovery.oak.OakDiscoveryService(256)] The updatedPropertyProvider method has thrown an exception (com.google.common.util.concurrent.ExecutionError: java.lang.AssertionError: This oak instance failed to update the lease in time and can therefore no longer access this DocumentNodeStore.)

I tried to solve problem according to adobe forum but I could not solve problem.

http://help-forums.adobe.com/content/adobeforums/en/experience-manager-forum/adobe-experience-manager.topic.html/forum__r93i-hi_friends_icam.html

Can someone help me why is this issue cause and let me know how to resolve this issue?

Regards

Answer 1

your problem is that you can't connect to the new primary mongodb instance (at least not in required time).. I would suggest to add a tag for mongodb to your question, because the question is related to mongodb and there are more users who know mongodb than jackrabbit-oak.. Back to the question: Can you ping your new primary node from the machine which is running your jackrabbit oak instance? How long does your replica set need to elect the new primary node? If this is longer than 10s, you will need to change some mongo db configuration settings. Can you post the result of rs.status()?

Answer 2

Thank you for your comment and suggestion.

I have solved this issue by myself. The way I approached is maybe correct.

This problem is WriteConcern parameter pased to MongoDBDriver in AEM. I changed mongi.uri to following, so this problem was solved.

-Doak.mongo.uri=mongodb://PrimaryHost:27017,SecondoryHost:27017/?replicaSet=rs0&readPreference=nearest
↓
-Doak.mongo.uri=mongodb://PrimaryHost:27017,SecondoryHost:27017/?replicaSet=rs0&readPreference=nearest&w=1&j=1

I forgot post regarding to my replica sets members. Our replica sets consist of Primary, Secondory, and Arbiter.

When I checked oak.jackrabit API, Default WriteConcern for MongoDiver is "majority" https://jackrabbit.apache.org/oak/docs/apidocs/org/apache/jackrabbit/oak/plugins/document/util/MongoConnection.html#getDefaultWriteConcern(com.mongodb.DB)

When one member of replica sets(exclude Arbiter) is down, AEM can't acknowledge write operation beacuse of write operation can't propagate to majority of member.

When I changed WriteConcern to w=1, write operation is acknowledged and AEM still work well.

How do you think this way? do you have any concern?