nav[aria-label="Primary Navigation"] { padding: 0; & ul { list-style: none; width: 100%; display: flex; flex-direction: row; justify-content: start; align-items: start; gap: 30px; padding: 0; & li { margin: 0; } & ul li { list-style: none; } } }

Afresco startup too slow

luca

Hi All,

I have some problems because Alfresco is taking too much to startup, actually it is taking 4 hours to complete.

I'm using Alfresco CE 4.2.d and we currently have approximately 700K documents that takes 600GB in total.

Can you help me why Alfresco is taking so much during startup?

Monitoring the machine I don't see any critical issue on memory, CPU or disk access on the startup time.

We are not using Solr, maybe this will have better performance?

I have attached the startup log.

sar13.pdf

alfresco-global.properties.zip

startup-2017-03-14.log.zip

Find more posts tagged with

Alfresco Content Services

Accepted answers

luca

Great news, I succesfully bring back the startup times to 21 min thanks to a tiny modifications to a single query!

The query is the one that I pointed out in a previous post and the complete explanation of the problem is described here: https://issues.alfresco.com/jira/browse/MNT-15576

Thank to all who helped me!

All comments

mehe

Hi Luca,

are you monitoring memory consumption on your system? But I don't know why alfresco tries to cache all the nodes...

We are using solr and are not encountering such boot times - normally alfresco boots within 5 minutes (about 1.000.000 docs). But if you depend heavily on transactional consistency on your index, you would have to brush up your code - solr works with eventual consistency, wich means simplified "if you do something, you won't find it immediately in your index, but later everything is fine".

My repository needs about 16GB of RAM for that amount of content, but solr also consumes a lot.

Have you tried to grant more memory to the JVM (and left enough for the OS)?

Is there something left in alfresco-global.properties that causes a full reindex on startup?

Is alfresco slow after the startup?

wishing the best for you

luca

Hi Martin,

I have added a report that shows you that the the machine is ok, as far as I see.

That machine has 16GB of RAM and Alfresco is using 6GB of it.

The index recovery is set to index.recovery.mode=AUTO, so there shouldn't be a reindex at startup.

After startup Alfresco is not slow, I noticed only a problem when I try to configure an advanced workflow when I search for groups the service goes in timeout (log: WARN [org.alfresco.authorityTransactionalCache] [ajp-apr-8010-exec-1] Transactional update cache 'org.alfresco.authorityTransactionalCache' is full (10000).).

Could this be culprit of cache?

I tried to double the cache of nodes setting this:

cache.node.nodesSharedCache.tx.maxItems=250000

cache.node.nodesSharedCache.maxItems=2500000

But Alfresco became 30min slower 😞

mehe

"Cache is full" is only a warning - so it's not the cause of your problem, but another symptom. Have you tried to decrease the cache size? If you say Alfresco is using 6GB, is it really using them or did you configure 6GB for the JVM?

Try to configure 8GB JVM memory then.

But everything smells like an Index problem. How long would it take to rebuild the complete index?

Personally I would switch to Solr in any case...

have to take some questions back, didn't realize the attached report on mobile...

afaust

Luca _ wrote:
The index recovery is set to index.recovery.mode=AUTO, so there shouldn't be a reindex at startup.

Actually, the AUTO recovery mode will perform a FULL re-index if it finds that the index does not have a valid index when that index does not even properly contain the initial transactions.

Regarding the caches: having transactional caches reported as full is not a catastrophic problem but it can have very serious problems to system performance.

Also, the correct solution for this would NOT be to increase the cache sizes (that kind of lazy suggestion I see all the time), but to identify the operation that is causing that much data to be loaded into caches in the first place. No default operation in Alfresco out-of-the-box should overwhelm the caches provided your data structure is sane (e.g. no overly excessive use of groups or secondary child associations) and you don't do queries for insanely large amounts of data in jobs / actions / any other kind of operation within a single transaction.

Setting nodesSharedCache to 2.5 million is a bold move, especially with the Alfresco default caches. I hope you haven't also increased the nodeAspectsShareCache and/or nodePropertiesSharedCache... This would dramatically increase the amount of heap used just for caching and can choke other processes in terms of "working memory".

Maybe you could provide your entire alfresco-global.properties configuration (anonymise sensitive data!) and list what kind of 3rd party addons / customisations you have applied to the system.

mehe

To identify the root-problem of your slow startup:

- did Alfresco take a long time for startup since the beginning (after containing a reasonable count of docs) ?

- if not, what did you change in your configuration that may have caused the issue?

- was there a kind of "mass changing" meta data or access rights or moving around large amounts of documents, resulting in huge transactions?

Another option: For offline analysing a copy of your lucene index, you can use Luke (getopft.org/luke).

luca

Hi Axel,

yesterday I restored the default cache configuration and give more memory to Alfresco raising it to 8GB, but the result is that this morning Alfresco took 4h 40min to startup, another 20min more than yesterday!! I didn't mention that Alfresco is shutten down at 2:55AM every night and restarted at 3:05AM using shutdown.sh and startup.sh scripts, could be that the indexes are not closed correctly? How can I check it?

I have added only the alfresco-trashcan-cleaner addon to empty the trashcan, but it is scheduled to run in the evening and an authentication filter based on shibbolet.

Also we have a lot of groups (49457 authorityContainer in DB, don't know if they are really groups) and users (about 13K).

I have attached also the alfresco-global.properties

luca

Hi Martin,

I added some other details in response to Axel.

This slow startup is an old problem that we ignored because if was restarting in the night when noone was working, but now I have some time to take a look at it. As far as I know there is not any action that I made that caused it suddendly, but it raised constantly.

For example these are some startup times that I registered:

24/08/2016 - 1h 50min
14/03/2017 - 3h 42min
15/03/2017 - 4h 19min - restart with nodesSharedCache raised
16/03/2017 - 4h 35min - restart with default cache and 8GB of mem

I will try to inspect indexes, the /opt/alf_data/lucene-indexes/archive/Spacestore folder is 497MB big, instead /opt/alf_data/lucene-indexes/workspace/spaceStore is 5GB big.

What I have to analize?

luca

I have just see that the DB is heavily used in the startup period, I will take a look deeper to find what it is happening.

luca

I have taken a look in the database and I saw this:

3:05 Alfresco start
Starting sysAdmin, Authentication subsystem
3:19 no more log in catalina.out till 5:29!
3:28 Here it starts doing the query below till 7:47
5:29 restart log: Startup of Search, thirdparty, OOoDirect, Transformers subsystems
5:40 no more log in catalina.out again till 7:47!
7:47 restart log: Starting fileServers, imap, email, Subscriptions subsystems
7:48 Alfresco startup completed

The query is this:

select
            node.id                 as node_id,
            node.version            as node_version,
            prop.qname_id           as qname_id,
            prop.locale_id          as locale_id,
            prop.list_index         as list_index,
            prop.actual_type_n      as actual_type_n,
            prop.persisted_type_n   as persisted_type_n,
            prop.boolean_value      as boolean_value,
            prop.long_value         as long_value,
            prop.float_value        as float_value,
            prop.double_value       as double_value,
            prop.string_value       as string_value,
            prop.serializable_value as serializable_value
        from
            alf_node node
            join alf_node_properties prop on (prop.node_id = node.id)
         WHERE  node_id in 
                ( $1, ..., $256 )

Why is it doing so many queries like that? It is possible that it is reindexing all the documents?
What can I do to understand what is it doing?

afaust

This type of query is typical for preloading a set of nodes into caches. That is usually a part of doing any kind of queries e.g. against SOLR.

luca

Ok, so you are telling me that Alfresco is loading nodes in the cache and this could be the reason that I see these logs:

 2017-03-16 03:21:15,658  WARN  [cache.node.nodesTransactionalCache] [localhost-startStop-1] Transactional update cache 'org.alfresco.cache.node.nodesTransactionalCache' is full (125000).  2017-03-16 03:21:40,089  WARN  [cache.node.aspectsTransactionalCache] [localhost-startStop-1] Transactional update cache 'org.alfresco.cache.node.aspectsTransactionalCache' is full (65000).  2017-03-16 03:21:43,413  WARN  [cache.node.propertiesTransactionalCache] [localhost-startStop-1] Transactional update cache 'org.alfresco.cache.node.propertiesTransactionalCache' is full (65000).

But I don't undestand why it is doing this, what do you mean by "That is usually a part of doing any kind of queries e.g. against SOLR."?

By the way, I'm not using SOLR, do you think that could solve my problems?