Replication Queue Exploded with more than 200,000 items

[samthadhani2]

Hi, We did some load tests where we were creating upto 3000 accounts in a minute and the test ran for few minutes. Since a lot of user data is created and replicated the replication queue is throwing exceptions.

Since CQ does not manage group replication really well. We have custom processes to manage it.

Basically each of our requests create upto 5 items within the queue and that is why the tests are failing. Is there any restriction on the number of items in the queue at any given point of time. Also, the items got cleared automatically from the queue when i looked at the queue in the morning so it was not that the queue was stuck because of any reason it was stuck because of extreme load.

Can we get rid of this somehow? Thanks. 

02.10.2014 03:46:40.110 WARN [192.168.140.21 [1412174743991] PUT /api/session/client/ondemand/user.desktop.v1.json HTTP/1.1] org.apache.jackrabbit.core.observation.ObservationDispatcher More than 200000 events in the queue java.lang.Exception: Stack Trace
at org.apache.jackrabbit.core.observation.ObservationDispatcher.delayIfEventQueueOverloaded(ObservationDispatcher.java:252)
at org.apache.jackrabbit.core.session.SessionState.perform(SessionState.java:246)
at org.apache.jackrabbit.core.NodeImpl.setProperty(NodeImpl.java:1920)
at org.apache.jackrabbit.core.NodeImpl.setProperty(NodeImpl.java:1890)
at client.core.services.user.verify.UserGroupOpeartionImpl.createPathWithProperties(UserGroupOpeartionImpl.java:245)
at client.core.services.user.verify.UserGroupOpeartionImpl.addMemberToGroup(UserGroupOpeartionImpl.java:150)
at client.core.services.user.register.UserCQSync.assignGroupsToUser(UserCQSync.java:192)
at client.core.services.user.register.UserCQSync.loginAndCreateUserNodes(UserCQSync.java:117)
at client.core.services.user.register.UserRegistrationServiceImpl.createUser(UserRegistrationServiceImpl.java:108)
at client.core.handlers.UserProfileResponseHandler.execute(UserProfileResponseHandler.java:158)
at client.core.services.endpoint.EndPointOptingServlet.execute(EndPointOptingServlet.java:325)
at client.core.services.endpoint.EndPointOptingServlet.doPut(EndPointOptingServlet.java:274)
at org.apache.sling.api.servlets.SlingAllMethodsServlet.mayService(SlingAllMethodsServlet.java:150)
at org.apache.sling.api.servlets.SlingSafeMethodsServlet.service(SlingSafeMethodsServlet.java:344)
at org.apache.sling.api.servlets.SlingSafeMethodsServlet.service(SlingSafeMethodsServlet.java:375)
at org.apache.sling.engine.impl.request.RequestData.service(RequestData.java:508)
at org.apache.sling.engine.impl.filter.SlingComponentFilterChain.render(SlingComponentFilterChain.java:45)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:64)
at com.day.cq.wcm.core.impl.WCMDebugFilter.doFilter(WCMDebugFilter.java:146)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at com.day.cq.wcm.core.impl.WCMComponentFilter.filterRootInclude(WCMComponentFilter.java:356)
at com.day.cq.wcm.core.impl.WCMComponentFilter.doFilter(WCMComponentFilter.java:168)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at client.core.services.filters.ResponseHeaderFilter.doFilter(ResponseHeaderFilter.java:166)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at com.day.cq.personalization.impl.TargetComponentFilter.doFilter(TargetComponentFilter.java:96)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at org.apache.sling.engine.impl.SlingRequestProcessorImpl.processComponent(SlingRequestProcessorImpl.java:254)
at org.apache.sling.engine.impl.filter.RequestSlingFilterChain.render(RequestSlingFilterChain.java:49)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:64)
at com.day.cq.wcm.core.impl.AuthoringUIModeServiceImpl.doFilter(AuthoringUIModeServiceImpl.java:301)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at com.day.cq.wcm.core.impl.warp.TimeWarpFilter.doFilter(TimeWarpFilter.java:106)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at com.day.cq.wcm.mobile.core.impl.redirect.RedirectFilter.doFilter(RedirectFilter.java:290)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at com.cognifide.cq.includefilter.DynamicIncludeFilter.doFilter(DynamicIncludeFilter.java:159)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at org.apache.sling.engine.impl.debug.RequestProgressTrackerLogFilter.doFilter(RequestProgressTrackerLogFilter.java:64)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at com.day.cq.wcm.foundation.forms.impl.FormsHandlingServlet.doFilter(FormsHandlingServlet.java:221)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at com.day.cq.theme.impl.ThemeResolverFilter.doFilter(ThemeResolverFilter.java:76)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at com.adobe.granite.optout.impl.OptOutFilter.doFilter(OptOutFilter.java:74)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at client.client.impl.filters.LoggingFilter.doFilter(LoggingFilter.java:40)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at client.ondemand.impl.filters.LoggingFilter.doFilter(LoggingFilter.java:40)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at client.news.impl.filters.LoggingFilter.doFilter(LoggingFilter.java:40)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at client.core.impl.filters.LoggingFilter.doFilter(LoggingFilter.java:40)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at com.day.cq.wcm.core.impl.WCMRequestFilter.doFilter(WCMRequestFilter.java:90)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at com.day.cq.wcm.designimporter.CanvasPageDeleteRequestFilter.doFilter(CanvasPageDeleteRequestFilter.java:88)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at org.apache.sling.rewriter.impl.RewriterFilter.doFilter(RewriterFilter.java:83)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
at org.apache.sling.i18n.impl.I18NFilter.doFilter(I18NFilter.java:127)
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)

[justin_at_adobe]

This warning refers to the JCR Observation queue, not the Replication queue.

This warning typically happens when there is a JCR Observation listener which is poorly behaved. It is unfortunately a bit tricky to figure out which one isn't behaving. One approach is to take thread dumps. Another is code review.

Regards,

Justin

[samthadhani2]

justin_at_adobe wrote...

This warning refers to the JCR Observation queue, not the Replication queue.

This warning typically happens when there is a JCR Observation listener which is poorly behaved. It is unfortunately a bit tricky to figure out which one isn't behaving. One approach is to take thread dumps. Another is code review.

Regards,

Justin

Ok, I have got launchers setup to listen to nt:unstructured node to reverse replicate and once reverse replicated to replicate to other publishers. I am doing some code review already and i have identified that i can lazy load stuff, so revere replicate only when needed.

[justin_at_adobe · Accepted solution]

SamThadhani wrote...

justin_at_adobe wrote...

This warning refers to the JCR Observation queue, not the Replication queue.

This warning typically happens when there is a JCR Observation listener which is poorly behaved. It is unfortunately a bit tricky to figure out which one isn't behaving. One approach is to take thread dumps. Another is code review.

Regards,

Justin

Ok, I have got launchers setup to listen to nt:unstructured node to reverse replicate and once reverse replicated to replicate to other publishers. I am doing some code review already and i have identified that i can lazy load stuff, so revere replicate only when needed.

One other thing to consider is to use a separate thread pool/queue, e.g. by calling Executors.newFixedThreadPool(1); so you do the actual work in a different thread. The JCR observation listener thus just gets the change set and then creates a Callable to be run later.