Uploaded image for project: 'PUBLIC - Liferay Portal Community Edition'
  1. PUBLIC - Liferay Portal Community Edition
  2. LPS-65033

Wrong logging level in LuceneHelperImpl

    Details

      Description

      [This issue happens in 6.2.x ]

      In com.liferay.portal.search.lucene.LuceneHelperImpl.addTerm(BooleanQuery, String, String, boolean, BooleanClauseOccur)
      there is a try-catch block for Exception. Its log level is "warn"

      It can occur that org.apache.lucene.search.BooleanQuery$TooManyClauses exception is thrown when clauses are more than maxClauseCount Lucenes's property (this can be configured by lucene.boolean.query.clause.max.size portal's property).

      As log level is "warn", it is complicated to detect this situation because no log message is written unless you change it (for example to "info").

      And catching the exception causes that maxClauseCount items are added to the BooleanQuery, so the results can mislead to user (for example when he is using an AssetPublisher)

      To diagnose what is happening could be improved changing the log level to "error", thus user can do it through log.

      Steps to reproduce:

      • Define in portal-ext.properties lucene.boolean.query.clause.max.size to 10
      • Create thirteen tags (for example: '01', '02', ..., '13')
      • Create a web content ('A') and set its categorization with tag '12'
      • Create a second web ('B') content and set its categorization with tag '13'
      • Add an Asset Publisher an configure with this settings:
        • Asset Selection -> Dynamic
        • Scope -> Current site
        • Asset type -> Any
        • Filter ->"Contains any of the following tags": '01', '02', '03', '04', '05', '06', '07', '08', '09', '10'.

      Check point 1:
      The Asset Publisher shows message "There are no results."

      • Reconfigure the Asset Publisher changing
        • Filter ->"Contains any of the following tags": '01', '02', '03', '04', '05', '06', '07', '08', '09', '10', '11'

      Observed behavior:
      The Asset Publisher shows message "There are no results."
      Portal log does not show any message

      Expected behavior:
      The Asset Publisher shows message "There are no results."
      Portal log shows

      08:37:53,876 WARN [RuntimePageImpl-2][LuceneHelperImpl:274] org.apache.lucene.search.BooleanQuery$TooManyClauses: maxClauseCount is set to 10 
      org.apache.lucene.search.BooleanQuery$TooManyClauses: maxClauseCount is set to 10 
      	at org.apache.lucene.search.BooleanQuery.add(BooleanQuery.java:136) 
      	at org.apache.lucene.search.BooleanQuery.add(BooleanQuery.java:127) 
      	at com.liferay.portal.search.lucene.LuceneHelperImpl._includeIfUnique(LuceneHelperImpl.java:1077) 
      	at com.liferay.portal.search.lucene.LuceneHelperImpl.addTerm(LuceneHelperImpl.java:270) 
      	at com.liferay.portal.search.lucene.LuceneHelperImpl.addTerm(LuceneHelperImpl.java:220) 
      	at com.liferay.portal.search.lucene.LuceneHelperUtil.addTerm(LuceneHelperUtil.java:268) 
      	at com.liferay.portal.search.lucene.LuceneHelperUtil.addTerm(LuceneHelperUtil.java:262) 
      	at com.liferay.portal.search.lucene.LuceneHelperUtil.addTerm(LuceneHelperUtil.java:256) 
      	at com.liferay.portal.search.lucene.BooleanQueryImpl.addTerm(BooleanQueryImpl.java:265) 
      	at com.liferay.portlet.assetpublisher.util.AssetSearcher.addSearchAnyTags(AssetSearcher.java:280) 
      	at com.liferay.portlet.assetpublisher.util.AssetSearcher.addSearchAssetTagNames(AssetSearcher.java:303) 
      	at com.liferay.portal.kernel.search.BaseIndexer.getFullQuery(BaseIndexer.java:271) 
      	at com.liferay.portal.kernel.search.BaseIndexer.doSearch(BaseIndexer.java:1418) 
      	at com.liferay.portal.kernel.search.DefaultSearchResultPermissionFilter.getHits(DefaultSearchResultPermissionFilter.java:75) 
      	at com.liferay.portal.kernel.search.BaseSearchResultPermissionFilter.search(BaseSearchResultPermissionFilter.java:54) 
      	at com.liferay.portal.kernel.search.BaseIndexer.search(BaseIndexer.java:582) 
      	at com.liferay.portlet.asset.util.AssetUtil.search(AssetUtil.java:716) 
      	at com.liferay.portlet.asset.util.AssetUtil.search(AssetUtil.java:661) 
      	at org.apache.jsp.html.portlet.asset_005fpublisher.view_jsp._jspService(Unknown Source) 
      ...
      
      • Change log level for com.liferay.portal.search.lucene.LuceneHelperImpl to WARN
        Control Panel -> Configuration -> Server Administration -> Log Levels -> Add Category
      • Go to page that contains the Asset Publisher

      Check point 2:
      The Asset Publisher shows message "There are no results."
      Portal log shows

      08:37:53,876 WARN [RuntimePageImpl-2][LuceneHelperImpl:274] org.apache.lucene.search.BooleanQuery$TooManyClauses: maxClauseCount is set to 10 
      org.apache.lucene.search.BooleanQuery$TooManyClauses: maxClauseCount is set to 10 
      	at org.apache.lucene.search.BooleanQuery.add(BooleanQuery.java:136) 
      	at org.apache.lucene.search.BooleanQuery.add(BooleanQuery.java:127) 
      	at com.liferay.portal.search.lucene.LuceneHelperImpl._includeIfUnique(LuceneHelperImpl.java:1077) 
      	at com.liferay.portal.search.lucene.LuceneHelperImpl.addTerm(LuceneHelperImpl.java:270) 
      	at com.liferay.portal.search.lucene.LuceneHelperImpl.addTerm(LuceneHelperImpl.java:220) 
      	at com.liferay.portal.search.lucene.LuceneHelperUtil.addTerm(LuceneHelperUtil.java:268) 
      	at com.liferay.portal.search.lucene.LuceneHelperUtil.addTerm(LuceneHelperUtil.java:262) 
      	at com.liferay.portal.search.lucene.LuceneHelperUtil.addTerm(LuceneHelperUtil.java:256) 
      	at com.liferay.portal.search.lucene.BooleanQueryImpl.addTerm(BooleanQueryImpl.java:265) 
      	at com.liferay.portlet.assetpublisher.util.AssetSearcher.addSearchAnyTags(AssetSearcher.java:280) 
      	at com.liferay.portlet.assetpublisher.util.AssetSearcher.addSearchAssetTagNames(AssetSearcher.java:303) 
      	at com.liferay.portal.kernel.search.BaseIndexer.getFullQuery(BaseIndexer.java:271) 
      	at com.liferay.portal.kernel.search.BaseIndexer.doSearch(BaseIndexer.java:1418) 
      	at com.liferay.portal.kernel.search.DefaultSearchResultPermissionFilter.getHits(DefaultSearchResultPermissionFilter.java:75) 
      	at com.liferay.portal.kernel.search.BaseSearchResultPermissionFilter.search(BaseSearchResultPermissionFilter.java:54) 
      	at com.liferay.portal.kernel.search.BaseIndexer.search(BaseIndexer.java:582) 
      	at com.liferay.portlet.asset.util.AssetUtil.search(AssetUtil.java:716) 
      	at com.liferay.portlet.asset.util.AssetUtil.search(AssetUtil.java:661) 
      	at org.apache.jsp.html.portlet.asset_005fpublisher.view_jsp._jspService(Unknown Source) 
      ...
      

      That is, it has been necessary to make a log level change.

      • Change log level for com.liferay.portal.search.lucene.LuceneHelperImpl to OFF
      • Reconfigure the Asset Publisher changing
        • Filter ->"Contains any of the following tags": '01', '02', '03', '04', '05', '06', '07', '08', '09', '10', '11', '12'

      Observed behavior:
      The Asset Publisher shows message "There are no results." (because '12' tag is out of lucene query)
      Portal log does not show any message

      Expected behavior:
      The Asset Publisher shows web content 'A' (because user knows that the Asset Publisher searches for '12' tag)
      Portal log shows

      08:37:53,876 WARN [RuntimePageImpl-2][LuceneHelperImpl:274] org.apache.lucene.search.BooleanQuery$TooManyClauses: maxClauseCount is set to 10 
      org.apache.lucene.search.BooleanQuery$TooManyClauses: maxClauseCount is set to 10 
      	at org.apache.lucene.search.BooleanQuery.add(BooleanQuery.java:136) 
      ...
      

      With this log message user could know that there is not any result in the Asset Publisher because '12' tag is out of lucene query.

      • Reconfigure the Asset Publisher changing
        • Filter ->"Contains any of the following tags": '01', '02', '03', '04', '05', '06', '07', '08', '12', '13'

      Observed and Expected behavior:
      The Asset Publisher shows web content 'A'
      The Asset Publisher shows web content 'B'

      • Reconfigure the Asset Publisher changing
        • Filter ->"Contains any of the following tags": '01', '02', '03', '04', '05', '06', '07', '08', '12', '09', '13'

      Observed behavior:
      The Asset Publisher shows web content 'A'
      The Asset Publisher does not show web content 'B' (because '13' tag is out of lucene query)
      Portal log does not show any message

      Expected behavior:
      The Asset Publisher shows web content 'A' (because user knows that the Asset Publisher searches for '12' tag)
      The Asset Publisher shows web content 'B' (because user knows that the Asset Publisher searches for '13' tag)
      Portal log shows

      08:37:53,876 WARN [RuntimePageImpl-2][LuceneHelperImpl:274] org.apache.lucene.search.BooleanQuery$TooManyClauses: maxClauseCount is set to 10 
      org.apache.lucene.search.BooleanQuery$TooManyClauses: maxClauseCount is set to 10 
      	at org.apache.lucene.search.BooleanQuery.add(BooleanQuery.java:136) 
      ...
      

      With this log message user could know that results in the Asset Publisher are wrong because '13' tag is out of lucene query.

      Check point 3:
      The Asset Publisher results can confuse to user but there is not any clue about that.


      With the proposed solution.

      • Define in portal-ext.properties lucene.boolean.query.clause.max.size to 10
      • Create thirteen tags (for example: '01', '02', ..., '13')
      • Create a web content ('A') and set its categorization with tag '12'
      • Create a second web ('B') content and set its categorization with tag '13'
      • Add an Asset Publisher an configure with this settings:
        • Asset Selection -> Dynamic
        • Scope -> Current site
        • Asset type -> Any
        • Filter ->"Contains any of the following tags": '01', '02', '03', '04', '05', '06', '07', '08', '09', '10'.

      Observed and Expected behavior:
      The Asset Publisher shows message "There are no results."

      • Reconfigure the Asset Publisher changing
        • Filter ->"Contains any of the following tags": '01', '02', '03', '04', '05', '06', '07', '08', '09', '10', '11'

      Observed and Expected behavior:
      The Asset Publisher shows message "There are no results."
      Portal log shows

      09:32:54,757 ERROR [RuntimePageImpl-2][LuceneHelperImpl:274] org.apache.lucene.search.BooleanQuery$TooManyClauses: maxClauseCount is set to 10 
      org.apache.lucene.search.BooleanQuery$TooManyClauses: maxClauseCount is set to 10 
      	at org.apache.lucene.search.BooleanQuery.add(BooleanQuery.java:136) 
      	at org.apache.lucene.search.BooleanQuery.add(BooleanQuery.java:127) 
      	at com.liferay.portal.search.lucene.LuceneHelperImpl._includeIfUnique(LuceneHelperImpl.java:1077) 
      	at com.liferay.portal.search.lucene.LuceneHelperImpl.addTerm(LuceneHelperImpl.java:270) 
      	at com.liferay.portal.search.lucene.LuceneHelperImpl.addTerm(LuceneHelperImpl.java:220) 
      	at com.liferay.portal.search.lucene.LuceneHelperUtil.addTerm(LuceneHelperUtil.java:268) 
      	at com.liferay.portal.search.lucene.LuceneHelperUtil.addTerm(LuceneHelperUtil.java:262) 
      	at com.liferay.portal.search.lucene.LuceneHelperUtil.addTerm(LuceneHelperUtil.java:256) 
      	at com.liferay.portal.search.lucene.BooleanQueryImpl.addTerm(BooleanQueryImpl.java:265) 
      	at com.liferay.portlet.assetpublisher.util.AssetSearcher.addSearchAnyTags(AssetSearcher.java:280) 
      	at com.liferay.portlet.assetpublisher.util.AssetSearcher.addSearchAssetTagNames(AssetSearcher.java:303) 
      	at com.liferay.portal.kernel.search.BaseIndexer.getFullQuery(BaseIndexer.java:271) 
      	at com.liferay.portal.kernel.search.BaseIndexer.doSearch(BaseIndexer.java:1418) 
      	at com.liferay.portal.kernel.search.DefaultSearchResultPermissionFilter.getHits(DefaultSearchResultPermissionFilter.java:75) 
      	at com.liferay.portal.kernel.search.BaseSearchResultPermissionFilter.search(BaseSearchResultPermissionFilter.java:54) 
      	at com.liferay.portal.kernel.search.BaseIndexer.search(BaseIndexer.java:582) 
      	at com.liferay.portlet.asset.util.AssetUtil.search(AssetUtil.java:716) 
      	at com.liferay.portlet.asset.util.AssetUtil.search(AssetUtil.java:661) 
      	at org.apache.jsp.html.portlet.asset_005fpublisher.view_jsp._jspService(Unknown Source) 
      	at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70) 
      	at javax.servlet.http.HttpServlet.service(HttpServlet.java:731) 
      	at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:439) 
      	at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:395) 
      	at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:339) 
      	at javax.servlet.http.HttpServlet.service(HttpServlet.java:731) 
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303) 
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) 
      	at com.liferay.portal.kernel.servlet.filters.invoker.InvokerFilterChain.doFilter(InvokerFilterChain.java:119) 
      	at com.liferay.portal.kernel.servlet.filters.invoker.InvokerFilter.doFilter(InvokerFilter.java:119) 
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) 
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) 
      	at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:748) 
      	at org.apache.catalina.core.ApplicationDispatcher.doInclude(ApplicationDispatcher.java:604) 
      	at org.apache.catalina.core.ApplicationDispatcher.include(ApplicationDispatcher.java:543) 
      	at com.liferay.portal.servlet.DirectServletPathRegisterDispatcher.include(DirectServletPathRegisterDispatcher.java:55) 
      	at com.liferay.portal.servlet.ClassLoaderRequestDispatcherWrapper.doDispatch(ClassLoaderRequestDispatcherWrapper.java:78) 
      	at com.liferay.portal.servlet.ClassLoaderRequestDispatcherWrapper.include(ClassLoaderRequestDispatcherWrapper.java:53) 
      	at com.liferay.taglib.util.IncludeTag.include(IncludeTag.java:290) 
      	at com.liferay.taglib.util.IncludeTag.doInclude(IncludeTag.java:184) 
      	at com.liferay.taglib.util.IncludeTag.doEndTag(IncludeTag.java:75) 
      	at org.apache.jsp.html.common.themes.portlet_jsp._jspService(Unknown Source) 
      
      ...
      
      • Reconfigure the Asset Publisher changing
        • Filter ->"Contains any of the following tags": '01', '02', '03', '04', '05', '06', '07', '08', '09', '10', '11', '12'

      Observed and Expected behavior:
      The Asset Publisher shows message "There are no results." (because '12' tag is out of lucene query)
      Portal log shows

      09:32:54,757 ERROR [RuntimePageImpl-2][LuceneHelperImpl:274] org.apache.lucene.search.BooleanQuery$TooManyClauses: maxClauseCount is set to 10 
      org.apache.lucene.search.BooleanQuery$TooManyClauses: maxClauseCount is set to 10 
      	at org.apache.lucene.search.BooleanQuery.add(BooleanQuery.java:136) 
      ...
      

      With this log message user could know that there is not any result in the Asset Publisher because '12' tag is out of lucene query.

      • Reconfigure the Asset Publisher changing
        • Filter ->"Contains any of the following tags": '01', '02', '03', '04', '05', '06', '07', '08', '12', '13'

      Observed and Expected behavior:
      The Asset Publisher shows web content 'A'
      The Asset Publisher shows web content 'B'

      • Reconfigure the Asset Publisher changing
        • Filter ->"Contains any of the following tags": '01', '02', '03', '04', '05', '06', '07', '08', '12', '09', '13'

      Observed and Expected behavior:
      The Asset Publisher shows web content 'A'
      The Asset Publisher does not show web content 'B' (because '13' tag is out of lucene query)
      Portal log shows

      09:32:54,757 ERROR [RuntimePageImpl-2][LuceneHelperImpl:274] org.apache.lucene.search.BooleanQuery$TooManyClauses: maxClauseCount is set to 10 
      org.apache.lucene.search.BooleanQuery$TooManyClauses: maxClauseCount is set to 10 
      	at org.apache.lucene.search.BooleanQuery.add(BooleanQuery.java:136) 
      ...
      

      With this log message user could know that results in the Asset Publisher are wrong because '13' tag is out of lucene query.

      Conclusion:
      The Asset Publisher results can confuse to user but now there is a clue about that and there is no need to set up any log level.

        Attachments

        1. fixed1.png
          fixed1.png
          162 kB
        2. fixed2.png
          fixed2.png
          17 kB
        3. fixed3.png
          fixed3.png
          135 kB
        4. reproduced1.png
          reproduced1.png
          179 kB
        5. reproduced2.png
          reproduced2.png
          14 kB
        6. reproduced3.png
          reproduced3.png
          10 kB

          Issue Links

            Activity

              People

              • Votes:
                0 Vote for this issue
                Watchers:
                1 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:
                  Days since last comment:
                  3 years, 29 weeks, 3 days ago

                  Packages

                  Version Package
                  6.2.X EE