SOLR causes high CPU usage on idle repo.

[kbryd]

Hi!

After installing a new repository (4.2.b community) on a rather slow PC (Intel E8400 2 core, 16GB of memory) and importing 100 small documents I noticed that every 15 seconds CPU usage jumps to almost 100% and operating system gets very sluggish. I have a similar issue on another (also almost empty) 4.0.b Community server.

I tracked it down to the setting in solrcore.properties:

alfresco.cron=0/15 * * * * ? *‍

When I change this to 60 seconds then (obviously) CPU usage jumps every (more or less) 60 seconds.

Question is: what happens every 15 seconds that Alfresco is using 90-100% of CPU? Can it be somehow minimized, optimized etc.? (in a different way than by tweaking cron setting).

Here is a fragment of log (which grows rather quickly):

127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:01 +0100] "GET /alfresco/service/api/solr/transactions?fromCommitTime=1354285578542&toCommitTime=1354289178542&maxResults=2000 HTTP/1.1" 200 272383
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:02 +0100] "GET /alfresco/service/api/solr/transactions?fromCommitTime=1354285879018&toCommitTime=1354289479018&maxResults=2000 HTTP/1.1" 200 272383
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:02 +0100] "GET /alfresco/service/api/solr/transactions?fromCommitTime=1354285278658&toCommitTime=1354288878658&maxResults=2000 HTTP/1.1" 200 272383
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:02 +0100] "GET /alfresco/service/api/solr/transactions?fromCommitTime=1354286179898&toCommitTime=1354289779898&maxResults=2000 HTTP/1.1" 200 84111
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:02 +0100] "GET /alfresco/service/api/solr/transactions?fromCommitTime=1354285578542&toCommitTime=1354289178542&maxResults=2000 HTTP/1.1" 200 272383
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:02 +0100] "GET /alfresco/service/api/solr/transactions?fromCommitTime=1354286269161&toCommitTime=1354289869161&maxResults=2000 HTTP/1.1" 200 254
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:02 +0100] "GET /alfresco/service/api/solr/transactions?fromCommitTime=1354289869161&toCommitTime=1354297069161&maxResults=2000 HTTP/1.1" 200 119
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:02 +0100] "GET /alfresco/service/api/solr/transactions?fromCommitTime=1354285879018&toCommitTime=1354289479018&maxResults=2000 HTTP/1.1" 200 272383
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:02 +0100] "GET /alfresco/service/api/solr/transactions?fromCommitTime=1354286179898&toCommitTime=1354289779898&maxResults=2000 HTTP/1.1" 200 84111
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:02 +0100] "GET /alfresco/service/api/solr/transactions?fromCommitTime=1354286269161&toCommitTime=1354289869161&maxResults=2000 HTTP/1.1" 200 254
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:02 +0100] "GET /alfresco/service/api/solr/transactions?fromCommitTime=1354289869161&toCommitTime=1354297069161&maxResults=2000 HTTP/1.1" 200 119
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:15 +0100] "POST /alfresco/service/api/solr/modelsdiff HTTP/1.1" 200 447
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:15 +0100] "POST /alfresco/service/api/solr/modelsdiff HTTP/1.1" 200 447
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:15 +0100] "GET /alfresco/service/api/solr/aclchangesets?fromTime=1354283154634&toTime=1354286754634&maxResults=2000 HTTP/1.1" 200 237
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:15 +0100] "GET /alfresco/service/api/solr/aclchangesets?fromTime=1354283154634&toTime=1354286754634&maxResults=2000 HTTP/1.1" 200 237
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:15 +0100] "GET /alfresco/service/api/solr/aclchangesets?fromTime=1354283154634&toTime=1354286754634&maxResults=2000 HTTP/1.1" 200 237
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:15 +0100] "GET /alfresco/service/api/solr/aclchangesets?fromTime=1354283154634&toTime=1354286754634&maxResults=2000 HTTP/1.1" 200 237
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:15 +0100] "GET /alfresco/service/api/solr/aclchangesets?fromTime=1354286754634&toTime=1354293954634&maxResults=2000 HTTP/1.1" 200 237
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:15 +0100] "GET /alfresco/service/api/solr/aclchangesets?fromTime=1354286754634&toTime=1354293954634&maxResults=2000 HTTP/1.1" 200 237
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:15 +0100] "GET /alfresco/service/api/solr/aclchangesets?fromTime=1354288551973&toTime=1354292151973&maxResults=2000 HTTP/1.1" 200 237
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:15 +0100] "GET /alfresco/service/api/solr/aclchangesets?fromTime=1354292151973&toTime=1354299351973&maxResults=2000 HTTP/1.1" 200 128
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:15 +0100] "GET /alfresco/service/api/solr/aclchangesets?fromTime=1354288551973&toTime=1354292151973&maxResults=2000 HTTP/1.1" 200 237
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:15 +0100] "GET /alfresco/service/api/solr/aclchangesets?fromTime=1354292151973&toTime=1354299351973&maxResults=2000 HTTP/1.1" 200 128
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:15 +0100] "GET /alfresco/service/api/solr/transactions?fromCommitTime=1354282238792&toCommitTime=1354285838792&maxResults=2000 HTTP/1.1" 200 270376
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:15 +0100] "GET /alfresco/service/api/solr/transactions?fromCommitTime=1354282238792&toCommitTime=1354285838792&maxResults=2000 HTTP/1.1" 200 270376
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:15 +0100] "GET /alfresco/service/api/solr/transactions?fromCommitTime=1354283479636&toCommitTime=1354287079636&maxResults=2000 HTTP/1.1" 200 271832
127.0.0.1 - CN=Alfresco Repository Client, OU=Unknown, O=Alfresco Software Ltd., L=Maidenhead, ST=UK, C=GB [30/Nov/2012:16:21:15 +0100] "GET /alfresco/service/api/solr/transactions?fromCommitTime=1354283479636&toCommitTime=1354287079636&maxResults=2000 HTTP/1.1" 200 271832
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

Thanks!
Karol

[andy]

Hi

SOLR is querying to see if anything has changed - it goes back an hour from the last thing in the index or the last time it checked - to make sure it has not missed anything.

It is likely the delay is the DB query to answer this question.
You can reduce the time it checks back in the config for the SOLR core.

What DB are you using?
Is the time in Java?

Andy

[andries]

The document ALFRESCO_HOME/alf_data/solr/HowToSetUpSolr.txt gives some info. This is Alfresco Community Editon 4.2.c. So I changed in these two files:
ALFRESCO_HOME/alf_data/solr/archive-SpacesStore/conf/solrcore.properties
ALFRESCO_HOME/alf_data/solr/workspace-SpacesStore/conf/solrcore.properties

Original line was (every 15 seconds)

alfresco.cron=0/15 * * * * ? *
‍‍‍

New line is (every 15 minutes)

alfresco.cron=0 0/15 * * * ? *
‍‍‍

Here is my question: Is this the preferred way of changing this setting?

[afaust]

Hello,

this is the preferred way of changing this setting. A repeat every 15 minutes is quite extreme - do you know that this means new content might not be available via search functionality (not just "search", but e.g. recently modified documents, documents I'm editing or documents others are editing) until the cron expressions triggers again?

Regards
Axel

[andries]

Thanks for your quick reply. And thanks for pointing out the consequences of changing this cron-setting. (off-topic: for my small test setup, this is acceptable; not so for a production environment)

[jego]

In this case, a better solr integration into Alfresco repository would not cause these problems, e.g. by using another approach of determine the changes in the repository. I don´t understand why SOLR has to ask for changes continously and the repository does not push the changes. This is a quite common pattern in enterprise integration. Can anybody explain me?

Nevertheless, there are some redundant requests from solr to repository in your first post. Is this caused by the multithreading solr tracker?
You can even try to reduce the threads from 4 to 2 or 1.

see <a href="http://wiki.alfresco.com/wiki/Alfresco_And_SOLR">http://wiki.alfresco.com/wiki/Alfresco_And_SOLR</a>

alfresco.corePoolSize=4
Pool size for multi-threaded tracking - use for indexing nodes
"1" means one thread indexing nodes and one tracking transactions
"4" means four threads indexing nodes and one tracking transactions

Thanks,
Jens
ACE

[afaust]

Hello,

pushing changes would require the very same approach of change set querying, since pushing changes to index shouldn't occur in-transaction as they were in the Lucene integration - otherwise one of the major benefits of the move to SOLR would be negated. And having SOLR pull instead of a push from the repository allows for a more flexible architecture than in the constellation where the repository were to control every aspect.

Of the top of my head, these would be my main questions / doubts regarding an alternative approach - I have actually not had the chance to work with a non-trivial / complex application that uses pushes instead of pulls, so maybe you could provide some input on these:
How would a full reindex be handled in a scenario where the repository pushes the changes?
How would I perform a recovery of a failed SOLR instances without interupting / interfering with the repository?
Would I have the same flexibility in terms of SOLR setup (active-passive instances, load-balancing) that I have now, without interupting / interfering with the repository?
(I count re-configuring at runtime via JMX as interfering)

Apart from the old (obsolete) version of SOLR being used and the lack of extensibility (for developers with sufficient expertise to even attempt this) I am quite pleased with the state of SOLR so far. I have not yet seen these extreme spikes in setups I have supported (including local, resource constrained VMs), so would like to have a more detailed basis on the original posters issue before making a guess what component to blame it on.

Regards
Axel

[andy]

Hi

The spike is actually caused by the tracker considering the last hour of transactions from the last thing it did (or now) so it does not miss anything. You can configure how far back it goes.

For example, if you use FTP to load up lots of files - there will be an hour where it is rechecking lots of stuff. Eventually this should go away.

However, if you are not expecting any long running transactions to pop into the transaction history feel free to tune this down.

alfresco.hole.retention=3600000

There are some other improvements on the list to check the full history less often.

In addition to the comments above on push vs pull

Push requires
- a queue - to know what has been pushed etc
  - effectively duplicating the existing transaction log
  - are you going to wait for it to push, queue  etc etc
- push can not coordinate commit
  - there is no way to insert a logical chunk of docs
  - any pushing thread can commit data pushed by others
  - you get more commits and more commit overhead
  - putting docs together makes sense
  - it is easy to configure
- You can build a super new index when we use SOLR 4 and not have to fix up the live instance, and switch to use it when you are done. Or rebuild to the side of your cluster etc etc

Axel, I would be interested to know what extension points you would like to see.

Andy 

Hope this helps

Andy 

[afaust]

Hello Andy,

it is not so much extension points that I want to see added, but a general enhancement in the direction of open API and modularity / extensibility. The main extension use case would be the implementation of additional index fields, i.e. meta fields like TYPE or ASPECT that don't directly index content or properties. We once implemented a COMMENT index field in Alfresco 3.4 which allowed users to lookup nodes by the comments associated with them. We also implemented a custom analyzer which allowed us to differentiate between public and user-specific comments.

Currently, the following limit the development of extensions / customizations:
<ul>
<li>inaccessible constructors, methods, members and classes (package protected, private or missing proper accessors), e.g. SolrLuceneAnalyser.findAnalyser / loadAnalyser, MultiThreadedCoreTracker or AlfrescoSolrDataModel</li>
<li>monolithic implementations that force subclassing and method overrides instead of plug-n-play additions, e.g. AbstractLuceneQueryParser, SOLRQueryHTTPClient.executeQuery, SolrLuceneAnalyser.findAnalyser, CoreTracker.indexNode or NodesMetadataGet web script</li>
<li>hard coded web script URIs</li>
</ul>

I know that providing extensibility features in this part of Alfresco requires a lot of walking the fine line between stability / supportability and freedom of development. I believe quite a few partners / community members already have ideas for valuable search capabilities they want to add / contribute back to the platform, but are currently unable / reluctant to implement even initial PoCs in the closed component that Alfresco SOLR is at the moment.

BTW: Is there some kind of longterm plan / vision to evaluate fine grained permissions in searches? E.g. not use the brute "Read" permission for ACL indexing, but low level "ReadProperties" and "ReadContent" (and possibly others). We have a couple of customers with business requirements that would only allow for searches to incorporate / weigh matches on the full text index of a content item if the user has the permission to actually view the content. Additionally, a new (custom) query field might need to have a subquery executed looking for a specific business permission.

Regards
Axel

[andy]

Hi

Adding custom fields to the SOLR index is on the list but has never made it to the top.
The other use case is to tag something in some part of a tree and avoid PATH queries.
A whole bunch of denormalisation stuff can go here but we also need to know when we have to reindex this stuff …. e.g. on move for the use case I have given, or when a new comment is added …

You can define an analyser bundle per model/type/aspect/property which covers most use cases for custom analysis. You can have per property analysis. We are assuming you will not have that many different analysers or the config gets a bit out of hand.

Splitting READ to reflect read content and metadata is not likely for a while …. However we are likely to change the way documents are split in the index (or not) in the future, or make it configurable. It seems likely we will split out content into a separate doc - at that point we can filter for read content and cache stuff. Yes we could do that as we go in the query - it is just neater if the whole doc is in or out.

It had not occurred to me that indexing the content on its own gave us that option too (as well as delaying indexing meta data). The additional cost is that rename, move, etc cause more work re-indexing the metadata.

Have you fed any of your observations back to Alfresco via any other routes?

Andy