Custom event listener on Oak+Mongo system causes Mongo Timeout

Issue

Custom JCR listener fails with error "java.lang.IllegalStateException: Branch with failed reset" on Oak Mongo DocumentNodeStore based AEM instances:

04.03.2017 04:55:52.810 *ERROR* [pool-6-thread-7] my.custom.PropertyChangeListener Branch with failed reset
java.lang.IllegalStateException: Branch with failed reset
at org.apache.jackrabbit.oak.plugins.document.DocumentNodeStoreBranch$ResetFailed.rebase(DocumentNodeStoreBranch.java:768)
at org.apache.jackrabbit.oak.plugins.document.DocumentNodeStoreBranch.rebase(DocumentNodeStoreBranch.java:184)
at org.apache.jackrabbit.oak.plugins.document.DocumentRootBuilder.rebase(DocumentRootBuilder.java:129)
at org.apache.jackrabbit.oak.plugins.document.DocumentNodeStore.rebase(DocumentNodeStore.java:1503)
at org.apache.jackrabbit.oak.core.MutableRoot.rebase(MutableRoot.java:223)
at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.refresh(SessionDelegate.java:497)
at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.prePerform(SessionDelegate.java:602)
at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.performNullable(SessionDelegate.java:232)
at org.apache.jackrabbit.oak.jcr.session.SessionImpl.getNodeOrNull(SessionImpl.java:178)
at org.apache.jackrabbit.oak.jcr.session.SessionImpl.nodeExists(SessionImpl.java:321)
at sun.reflect.GeneratedMethodAccessor57.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.apache.sling.jcr.base.SessionProxyHandler$SessionProxyInvocationHandler.invoke(SessionProxyHandler.java:113)
at com.sun.proxy.$Proxy7.nodeExists(Unknown Source)
at my.custom.PropertyChangeListener.onEvent(PropertyChangeListener.java:145)
at org.apache.jackrabbit.commons.observation.ListenerTracker$1.onEvent(ListenerTracker.java:164)
at org.apache.jackrabbit.oak.jcr.observation.ChangeProcessor.contentChanged(ChangeProcessor.java:316)
at org.apache.jackrabbit.oak.spi.commit.BackgroundObserver$1$1.call(BackgroundObserver.java:131)
at org.apache.jackrabbit.oak.spi.commit.BackgroundObserver$1$1.call(BackgroundObserver.java:125)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.jackrabbit.oak.api.CommitFailedException: OakOak0100: Branch reset failed
at org.apache.jackrabbit.oak.plugins.document.DocumentNodeStoreBranch$Persisted.resetBranch(DocumentNodeStoreBranch.java:689)
at org.apache.jackrabbit.oak.plugins.document.DocumentNodeStoreBranch$Persisted.merge(DocumentNodeStoreBranch.java:673)
at org.apache.jackrabbit.oak.plugins.document.DocumentNodeStoreBranch.merge0(DocumentNodeStoreBranch.java:223)
at org.apache.jackrabbit.oak.plugins.document.DocumentNodeStoreBranch.merge(DocumentNodeStoreBranch.java:171)
at org.apache.jackrabbit.oak.plugins.document.DocumentRootBuilder.merge(DocumentRootBuilder.java:158)
at org.apache.jackrabbit.oak.plugins.document.DocumentNodeStore.merge(DocumentNodeStore.java:1497)
at org.apache.jackrabbit.oak.core.MutableRoot.commit(MutableRoot.java:247)
at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.commit(SessionDelegate.java:339)
at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.save(SessionDelegate.java:485)
at org.apache.jackrabbit.oak.jcr.session.SessionImpl$8.performVoid(SessionImpl.java:424)
at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.performVoid(SessionDelegate.java:266)
at org.apache.jackrabbit.oak.jcr.session.SessionImpl.save(SessionImpl.java:421)
at sun.reflect.GeneratedMethodAccessor82.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.apache.sling.jcr.base.SessionProxyHandler$SessionProxyInvocationHandler.invoke(SessionProxyHandler.java:113)
at com.sun.proxy.$Proxy7.save(Unknown Source)
at my.custom.PropertyChangeListener.reportSyncEvent(PropertyChangeListener.java:244)
at my.custom.PropertyChangeListener.onEvent(PropertyChangeListener.java:135)
... 8 common frames omitted
Caused by: com.mongodb.MongoExecutionTimeoutException: operation exceeded time limit
at com.mongodb.QueryResultIterator.throwOnQueryFailure(QueryResultIterator.java:244)
at com.mongodb.QueryResultIterator.init(QueryResultIterator.java:224)
at com.mongodb.QueryResultIterator.initFromQueryResponse(QueryResultIterator.java:184)
at com.mongodb.QueryResultIterator.getMore(QueryResultIterator.java:149)
at com.mongodb.QueryResultIterator.hasNext(QueryResultIterator.java:135)
at com.mongodb.DBCursor._hasNext(DBCursor.java:626)
at com.mongodb.DBCursor.hasNext(DBCursor.java:657)
at org.apache.jackrabbit.oak.plugins.document.mongo.MongoDocumentStore.queryInternal(MongoDocumentStore.java:587)
at org.apache.jackrabbit.oak.plugins.document.mongo.MongoDocumentStore.query(MongoDocumentStore.java:518)
at org.apache.jackrabbit.oak.plugins.document.DocumentNodeStore.diffManyChildren(DocumentNodeStore.java:2249)
at org.apache.jackrabbit.oak.plugins.document.DocumentNodeStore.diffImpl(DocumentNodeStore.java:2217)

Cause

Known issue caused by bug OAK-4503

Resolution

Apply the latest Oak Cumulative Fix Pack applicable to the AEM version you are using: