High CPU consumption with Lucene search

• Type: Bug
• Status: Closed
• Resolution: Fixed
• Affects Version/s: 6.2.X EE
• Fix Version/s: 6.2.4 CE GA5, 6.2.X EE
• Component/s: Performance, Search Infrastructure, Search Infrastructure > Lucene Impl
• Labels:
  • 6.2.x-only
  • liferay-fixpack-portal-69-6210
  • performance
• Branch Version/s:
  6.2.x
• Backported to Branch:
  Committed
• Story Points: 27
• Fix Priority: 3
• Git Pull Request: https://github.com/hhuijser/liferay-portal-ee/pull/2597

When the Lucene index is used to search (i.e. Asset Publisher), and a profile of Liferay Portal is done, a great amount of CPU is used in com.liferay.portal.search.lucene.highlight.QueryTermExtractor.getTerms (see attached image: profile.png)

If thread dumps are taken in those moments when CPU use is high, a lot of threads are running at this point:

"http-/10.187.162.42:8081-362" daemon prio=10 tid=0x00007fbd24bd0800 nid=0x3e48 runnable [0x00007fbbc2fa5000]
   java.lang.Thread.State: RUNNABLE
	at com.liferay.portal.search.lucene.highlight.QueryTermExtractor.getTerms(QueryTermExtractor.java:41)
	at com.liferay.portal.search.lucene.LuceneHelperImpl.countScoredFieldNames(LuceneHelperImpl.java:314)
	at com.liferay.portal.search.lucene.LuceneHelperUtil.countScoredFieldNames(LuceneHelperUtil.java:296)
	at com.liferay.portal.search.lucene.LuceneIndexSearcher.toHits(LuceneIndexSearcher.java:621)
	at com.liferay.portal.search.lucene.LuceneIndexSearcher.search(LuceneIndexSearcher.java:246)
	at sun.reflect.GeneratedMethodAccessor1395.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.liferay.portal.kernel.messaging.proxy.ProxyRequest.execute(ProxyRequest.java:85)
	at com.liferay.portal.kernel.messaging.proxy.ProxyMessageListener.receive(ProxyMessageListener.java:51)
	at com.liferay.portal.kernel.messaging.InvokerMessageListener.receive(InvokerMessageListener.java:72)
	at com.liferay.portal.kernel.messaging.SynchronousDestination.send(SynchronousDestination.java:41)
	at com.liferay.portal.kernel.messaging.sender.DirectSynchronousMessageSender.send(DirectSynchronousMessageSender.java:54)
	at com.liferay.portal.kernel.messaging.proxy.BaseMultiDestinationProxyBean.synchronousSend(BaseMultiDestinationProxyBean.java:48)
	at com.liferay.portal.messaging.proxy.MultiDestinationMessagingProxyInvocationHandler.invoke(MultiDestinationMessagingProxyInvocationHandler.java:50)
	at com.sun.proxy.$Proxy288.search(Unknown Source)
	at com.liferay.portal.kernel.search.SearchEngineUtil.search(SearchEngineUtil.java:671)
	at com.liferay.portal.kernel.search.BaseIndexer.doSearch(BaseIndexer.java:1364)
	at com.liferay.portal.kernel.search.DefaultSearchResultPermissionFilter.getHits(DefaultSearchResultPermissionFilter.java:94)
	at com.liferay.portal.kernel.search.BaseSearchResultPermissionFilter.search(BaseSearchResultPermissionFilter.java:70)
	at com.liferay.portal.kernel.search.BaseIndexer.search(BaseIndexer.java:527)
	at com.liferay.portlet.asset.util.AssetUtil.search(AssetUtil.java:626)
	at com.liferay.portlet.asset.util.AssetUtil.search(AssetUtil.java:571)
	at org.apache.jsp.html.portlet.asset_005fpublisher.view_jsp._jspService(view_jsp.java:1931)

Steps to reproduce:

1. Start a clean 6.2.x bundle (tested using these JVM options: -Xmx1624m -XX:MaxPermSize=512m).
2. As an admin, execute the attached groovy script (Create_contents.groovy) changing the groupId from the script to the groupId of your default site from Control Panel.
3. When script is completed, add a new page named "ap".
4. Add an Asset Publisher in "ap" page.
5. Download JMeter (tested with 2.13) and extract in some directory.
6. Download JMeter Standard Set (downloaded here: http://jmeter-plugins.org/downloads/file/JMeterPlugins-Standard-1.3.0.zip) and install in previous installed JMeter.
7. Download JMeter ServerAgent from http://jmeter-plugins.org/downloads/file/ServerAgent-2.2.1.zip. Extract compressed to any directory and execute "bin/startAgent.bat" or "startAgent.sh" depending on Windows/Linux environment.
8. Open JMeter, and open the attached file (LPS-56035_test.jmx).
9. Execute test plan clicking on play button in toolbar. Wait until it ends (that should happen when "Stop" button gets disabled).
10. In the test plan tree (left), click on "Responses time over time". Save the chart (optionally save the CSV to compare using a spreadsheet). Optional: execute the test plan more times for getting more accurate measures to compare. Optional: save the "Perfmon metrics collector" to get CPU measures.
11. Shutdown Liferay and start up with this fix applied. After the fix, redo steps from 8 to 10 and save the targeted graphs/CSV
12. Compare the results from before and after the fix.

After the fix the Response time over time results in "Ap request" are noticeable lower (14,7% better performance than before).