Length of time for building search / lucene indexes

Products

• CA Automic Workload Automation - Automation Engine
• CA Automic One Automation

Issue/Introduction

After upgrading Automation Engine, the search is unavailable for some time while rebuilding the search (Lucene) index.  It looks like the JWP handles this based on the role IDX in the Administration perspective under Automation Engine management.  At the same time, the search functionality can find tasks that match a search, but doesn't find objects when they do exist.  When looking at a search result, it shows "Incomplete search results. Index not yet finished."

Is there a way to know that the indexes are being properly built?
How long should it take?  
Is a long time normal?

Resolution

When the JWPs are started up, one of them (per server) becomes assigned the index or IDX role, as shown in the Administration perspective.  The size of the index and amount of time that it takes to fully build or rebuild that index will vary a lot system to system since every system is different.  There's no exact way to find out how long the indexing will take, but we can get somewhat of an indication by looking at the IDX JWP log.  Here's a snippet from an example system that's fairly small, but can help to see the overall picture:

20231103/114152.132 - 39     U00045136 Search index update: Detected 2972 objects which need to be re-indexed. 33 objects are being removed. (0.470s)
20231103/114152.132 - 39     U00045133 Search index update: executing 1 partition(s) for 33 deleted object(s).
20231103/114152.164 - 39     U00045134 Search index update: partition #0 finished (0.032s).
20231103/114152.164 - 39     U00045122 Search index update: updated 33 objects (0.580s)
20231103/114152.164 - 39     U00045133 Search index update: executing 1 partition(s) for 92 modified calendar event object(s).
20231103/114153.900 - 39     U00045134 Search index update: partition #0 finished (1.736s).
20231103/114153.900 - 39     U00045122 Search index update: updated 92 objects (2.316s)
20231103/114153.915 - 39     U00045133 Search index update: executing 3 partition(s) for 2972 modified object(s).
20231103/114156.909 - 39     U00045134 Search index update: partition #0 finished (2.994s).
20231103/114158.221 - 42     U00045159 Thread 'MQWorker-1'  has ID '45'.
20231103/114158.988 - 39     U00045363 Search index update: The object webservicerest in client 0 could not be indexed because it contains an invalid XML.
20231103/114203.420 - 39     U00045134 Search index update: partition #1 finished (6.511s).
20231103/114204.646 - 39     U00045363 Search index update: The object dna in client 0 could not be indexed because it contains an invalid XML.
20231103/114205.508 - 39     U00045134 Search index update: partition #2 finished (2.088s).
20231103/114205.508 - 39     U00045122 Search index update: updated 2972 objects (13.924s)

The first message (U00045136) indicates how many objects need to be indexed:
Detected 2972 objects

The next message to look at will be U00045133 Search index update: executing 3 partition(s) for 2972 modified object(s).

We can see from this that the index will be in 3 partitions (there's about 1000 objects per partition).

Then looking at how long the partitions take:

20231103/114203.420 - 39     U00045134 Search index update: partition #1 finished (6.511s).
20231103/114205.508 - 39     U00045134 Search index update: partition #2 finished (2.088s).

In this case it took 8.5 seconds, so an average of 4 to 4.5 seconds.  On a bigger system, you can get a better idea of what the average time per partition is and can kind of guesstimate off of this how long it will take.  In this case, had there been 100 partitions, we could have estimated that it would take around 450 seconds or 7.5 minutes.  

Finally, you'll know that the indexing is finished when the message:
20231103/114205.508 - 39     U00045122 Search index update: updated 2972 objects (13.924s)

shows up in the logs.  A lot of customers completely rebuild their indexes when they upgrade to a new major versions (for example 12.3 to 21.0) since there are many changes and it can avoid possible corruption of the search index which then requires a rebuild anyways.

If it's taking a long time and there are a lot of time critical database calls, this also might be normal.  There are some helpful hints to look at in the following article: AWA: JCP/JWP shows long running calls against IndexBuilder/TIMER