Query Builder does not work on 1 publisher instance

bryane54211190

28-02-2020

We have a component that runs a query builder to generate an RSS feed of blog posts.  This component seems to work fine on all environments (We are hosted on AMS with a dev environment, stage and production) on both author and publish instances except for our production publisher 1 instance (we have 2 publish servers in production).  

 

This does not seem to be an issue with our component itself as I've tried debugging the query in the Query Builder Debugger and the query works fine everywhere but still fails in the debugger on the production publisher 1 instance.  

 

The query looks like:

path=/content/rsadev/en-us/blog
type=cq:PageContent
orderby=@publishDate
orderby.sort=desc
property=cq:template
property.value=/apps/rsa-www/templates/blogpost
p.facets=true

 

When I run this on any instance except Publisher 1 I get results fine (the query takes .04 seconds).  When I try and run this on the Publisher 1 instance.  It just gets stuck saying "Running search..."  and results are never returned.  

 

I was wondering if this is possibly an issue with Oak Indices, but I've tried doing reindexes on certain indexes (by toggling the reindex property to true and saving within CRXDE Lite) on the publisher 1 instance, but so far, doing this does not seem to have any effect.  

 

I also tried enabling query logging for a little bit of time, and on publisher 1 the query seems to execute in 0ms:

 

27.02.2020 18:46:00.956 *DEBUG* [10.153.72.93 [1582829160951] GET /en-us/blog.rss.xml HTTP/1.1] com.day.cq.search.impl.builder.QueryImpl executing query (predicate tree):
ROOT=group: limit=10, facets=true[
{orderby=orderby: orderby=@publishDate, sort=desc}
{path=path: path=/content/rsadev/en-us/blog}
{property=property: property=cq:template, value=/apps/rsa-www/templates/blogpost}
{type=type: type=cq:PageContent}
]
27.02.2020 18:46:00.956 *DEBUG* [10.153.72.93 [1582829160951] GET /en-us/blog.rss.xml HTTP/1.1] com.day.cq.search.impl.builder.QueryImpl entire query execution took 0 ms
27.02.2020 18:46:00.960 *DEBUG* [10.153.72.93 [1582829160951] GET /en-us/blog.rss.xml HTTP/1.1] org.apache.jackrabbit.oak.plugins.index.property.PropertyIndex property cost for uuid is 2.0
27.02.2020 18:46:01.399 *DEBUG* [qtp412203417-3417104] org.apache.jackrabbit.oak.plugins.index.property.PropertyIndex property cost for uuid is 2.0
27.02.2020 18:46:01.402 *DEBUG* [10.153.72.93 [1582829161400] GET /libs/granite/csrf/token.json HTTP/1.1] org.apache.jackrabbit.oak.plugins.index.property.PropertyIndex property cost for uuid is 2.0
27.02.2020 18:46:01.513 *DEBUG* [sling-oak-103-org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate-async] org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate [async] Running background index task
27.02.2020 18:46:01.513 *DEBUG* [sling-oak-103-org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate-async] org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate [async] No changes since last checkpoint; skipping the index update
27.02.2020 18:46:01.522 *DEBUG* [sling-oak-100-org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate-fulltext-async] org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate [fulltext-async] Running background index task
27.02.2020 18:46:01.522 *DEBUG* [sling-oak-100-org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate-fulltext-async] org.apache.jackrabbit.oak.plugins.index.AsyncIndexUpdate [fulltext-async] No changes since last checkpoint; skipping the index update
27.02.2020 18:46:02.228 *DEBUG* [qtp412203417-3417380] org.apache.jackrabbit.oak.plugins.index.property.PropertyIndex property cost for uuid is 2.0
27.02.2020 18:46:02.233 *DEBUG* [10.153.72.93 [1582829162230] POST /en-us/index.html HTTP/1.1] org.apache.jackrabbit.oak.plugins.index.property.PropertyIndex property cost for uuid is 2.0
27.02.2020 18:46:02.472 *DEBUG* [qtp412203417-3417104] org.apache.jackrabbit.oak.plugins.index.property.PropertyIndex property cost for uuid is 2.0
27.02.2020 18:46:02.475 *DEBUG* [10.153.72.93 [1582829162473] GET /libs/granite/csrf/token.json HTTP/1.1] org.apache.jackrabbit.oak.plugins.index.property.PropertyIndex property cost for uuid is 2.0
27.02.2020 18:46:02.771 *DEBUG* [qtp412203417-3417380] org.apache.jackrabbit.oak.plugins.index.property.PropertyIndex property cost for uuid is 2.0
27.02.2020 18:46:02.857 *DEBUG* [qtp412203417-3417104] org.apache.jackrabbit.oak.plugins.index.property.PropertyIndex property cost for uuid is 2.0
27.02.2020 18:46:02.932 *DEBUG* [qtp412203417-3417380] org.apache.jackrabbit.oak.plugins.index.property.PropertyIndex property cost for uuid is 2.0

 

 

Any recommendations about things to look at or items to research would be greatly appreciated.

Accepted Solutions (1)

Accepted Solutions (1)

bryane54211190

12-03-2020

Just a follow up to this.  I worked with the Adobe Managed Services team on this and after a few unsuccessful rounds attempting to rebuild the indexes using the tool mentioned at:

https://docs.adobe.com/content/help/en/experience-manager-learn/foundation/administration/use-oak-ru... the issue was eventually resolved by the AMS team by copying the working index from publisher 2 to the publisher 1 instance.

 

Answers (3)

Answers (3)

jakej40603950

02-03-2020

Are you sure you're the indexes look the same on all your publish instances?

Could you compare the entire oak:index node tree in the working and non-working instances (by perhaps using infinity.json or by packaging them up, downloading the package and comparing the xml contained within)?

Jörg_Hoh

Employee

29-02-2020

The fact that the query is not returning typically means that it started a traversal instead of using an index. Typically you can see this in the logs (error.log) even without setting anything to debug. If it does not, please trigger the query and then do a few threaddumps in an interval of a few seconds; it should be easy to spot the relevant thread and find out what it is doing.

Thanks for your reply.

When I try and view the rss page which performs the query I get a server 500 error and this appears in the error.log

 

02.03.2020 00:00:37.159 *ERROR* GET /en-us/blog.rss.xml HTTP/1.1] org.apache.sling.engine.impl.SlingRequestProcessorImpl service: Uncaught SlingException
org.apache.sling.scripting.sightly.SightlyException: org.apache.sling.api.SlingException: Cannot get DefaultSlingScript: org.mozilla.javascript.WrappedException: Wrapped java.lang.NullPointerException (/libs/wcm/foundation/components/list/list.js#517)
at com.adobe.cq.sightly.WCMScriptHelper.includeResource(WCMScriptHelper.java:184) [com.adobe.cq.sightly.cq-wcm-sightly-extension:1.5.12]
at com.adobe.cq.sightly.internal.extensions.ResourceExtension.call(ResourceExtension.java:139) [com.adobe.cq.sightly.cq-wcm-sightly-extension:1.5.12]
at org.apache.sling.scripting.sightly.impl.engine.runtime.RenderContextImpl.call(RenderContextImpl.java:69) [org.apache.sling.scripting.sightly:1.0.54.1_4_0]
at org.apache.sling.scripting.sightly.apps.rsa__002d__www.page.blogindex.rss_xml_html.render(rss_xml_html.java:44)
at org.apache.sling.scripting.sightly.java.compiler.RenderUnit.render(RenderUnit.java:48) [org.apache.sling.scripting.sightly.compiler.java:1.0.24.1_4_0]
at org.apache.sling.scripting.sightly.impl.engine.SightlyCompiledScript.eval(SightlyCompiledScript.java:61) [org.apache.sling.scripting.sightly:1.0.54.1_4_0]
at org.apache.sling.scripting.core.impl.DefaultSlingScript.call(DefaultSlingScript.java:386) [org.apache.sling.scripting.core:2.0.54]
at org.apache.sling.scripting.core.impl.DefaultSlingScript.eval(DefaultSlingScript.java:184) [org.apache.sling.scripting.core:2.0.54]
at org.apache.sling.scripting.core.impl.DefaultSlingScript.service(DefaultSlingScript.java:491) [org.apache.sling.scripting.core:2.0.54]
at org.apache.sling.engine.impl.request.RequestData.service(RequestData.java:552) [org.apache.sling.engine:2.6.12]
at org.apache.sling.engine.impl.filter.SlingComponentFilterChain.render(SlingComponentFilterChain.java:44) [org.apache.sling.engine:2.6.12]
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:77) [org.apache.sling.engine:2.6.12]
at com.day.cq.wcm.core.impl.WCMDeveloperModeFilter.doFilter(WCMDeveloperModeFilter.java:119) [com.day.cq.wcm.cq-wcm-core:5.11.240]
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:68) [org.apache.sling.engine:2.6.12]
at com.day.cq.wcm.core.impl.WCMDebugFilter.doFilterWithErrorHandling(WCMDebugFilter.java:192) [com.day.cq.wcm.cq-wcm-core:5.11.240]
at com.day.cq.wcm.core.impl.WCMDebugFilter.doFilter(WCMDebugFilter.java:159) [com.day.cq.wcm.cq-wcm-core:5.11.240]
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:68) [org.apache.sling.engine:2.6.12]
at com.day.cq.wcm.core.impl.WCMComponentFilter.doFilter(WCMComponentFilter.java:278) [com.day.cq.wcm.cq-wcm-core:5.11.240]
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:68) [org.apache.sling.engine:2.6.12]
at com.day.cq.wcm.core.impl.PageLockFilter.doFilter(PageLockFilter.java:91) [com.day.cq.wcm.cq-wcm-core:5.11.240]
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:68) [org.apache.sling.engine:2.6.12]
at com.day.cq.personalization.impl.TargetComponentFilter.doFilter(TargetComponentFilter.java:96) [com.day.cq.cq-personalization:5.11.58]
at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:68) [org.apache.sling.engine:2.6.12]
at org.apache.sling.engine.impl.SlingRequestProcessorImpl.processComponent(SlingRequestProcessorImpl.java:282) [org.apache.sling.engine:2.6.12]
at org.apache.sling.engine.impl.SlingRequestProcessorImpl.dispatchRequest(SlingRequestProcessorImpl.java:322) [org.apache.sling.engine:2.6.12]
at org.apache.sling.engine.impl.request.SlingRequestDispatcher.dispatch(SlingRequestDispatcher.java:211) [org.apache.sling.engine:2.6.12]
at org.apache.sling.engine.impl.request.SlingRequestDispatcher.include(SlingRequestDispatcher.java:104) [org.apache.sling.engine:2.6.12]
at com.day.cq.wcm.core.impl.WCMComponentFilter$ForwardRequestDispatcher.include(WCMComponentFilter.java:516) [com.day.cq.wcm.cq-wcm-core:5.11.240]
at org.apache.jsp.libs.cq.Page.Page_xml_jsp._jspService(Page_xml_jsp.java:117)
at org.apache.sling.scripting.jsp.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70) [org.apache.sling.scripting.jsp:2.2.7.B002]

 

... error continues but exceeds maximum character length of a post

anji0723

29-02-2020

@bryane54211190 Have you reindex the cqPageLucene Index and check the cost of the query and index used in your query at http://localhost:4502/libs/granite/operations/content/diagnosistools/queryPerformance.html .

Yes, I've tried to reindex cqPageLucene (by toggling the reindex value to true in crxde lite). When I try and view the queryPerformance tool and do an Explain Query on my query i get an error popup:

An error occurred while explaining the query.

 

null
com.day.cq.search.impl.builder.QueryBuilderImpl.getComponent(QueryBuilderImpl.java:278)
com.day.cq.search.impl.builder.QueryImpl.getPredicateEvaluator(QueryImpl.java:250)
com.day.cq.search.impl.builder.EvaluationContextImpl.getPredicateEvaluator(EvaluationContextImpl.java:51)
com.day.cq.search.eval.PredicateGroupEvaluator.getXPathExpression(PredicateGroupEvaluator.java:106)
com.day.cq.search.impl.builder.RootEvaluator.getPropertyConstraintsXpathSubExpre(RootEvaluator.java:437)
com.day.cq.search.impl.builder.RootEvaluator.getAllSubQueryObjects(RootEvaluator.java:399)
com.day.cq.search.impl.builder.RootEvaluator.getXPathExpressionWithUnion(RootEvaluator.java:261)
com.day.cq.search.impl.builder.RootEvaluator.getXPathExpression(RootEvaluator.java:95)
com.day.cq.search.impl.builder.QueryImpl.executeXpath(QueryImpl.java:385)
com.day.cq.search.impl.builder.QueryImpl.execute(QueryImpl.java:442)

 

Just to follow up on this. I ran the query performance tool on our publisher 2 instance where the query works and it is actually using a different index, ntBaseLucene and properly gives logs. It is only on the Publisher 1 instance that I get the error. I've tried reindexing the ntBaseLucene index but I still get the error when attempting to explain the query.