Full Elasticsearch Indexing

Hi :slight_smile:

We have imported about 2.4 million contacts and about 300,000 accounts into SuiteCRM and are currently struggling to perform a full indexing after setting up Elasticsearch.

The indexing always terminates because of too much memory consumption from the PHP process - whatever memory_limit is set, let it be 256M, 512M or even more.

When running the indexing manually via

robo elastic:index

the outcome always is:

root@afbf2ebc14d8:/bitnami/suitecrm# vendor/bin/robo elastic:index
[=][13:40:13] Starting indexing procedures
[@][13:40:13] Indexing is performed using JsonSerializerDocumentifier
[@][13:40:13] Reading lock file cache/ElasticSearchIndexer.lock
[@][13:40:13] Lock file not found
[@][13:40:13] A full indexing will be performed
[@][13:40:13] Removed index 'main'
[@][13:40:13] Loading mapping file /bitnami/suitecrm/lib/Search/ElasticSearch/defaultParams.yml
[@][13:40:14] Created new index 'main'
PHP Fatal error: Allowed memory size of 4294967296 bytes exhausted (tried to allocate 12288 bytes) in /bitnami/suitecrm/data/SugarBean.php on line 481
ERROR: Allowed memory size of 4294967296 bytes exhausted (tried to allocate 12288 bytes)
in /bitnami/suitecrm/data/SugarBean.php:481

When setting the log level to “DEBUG” there are just too many entries to be able to tell which of those are really relevant.

The SuiteCRM version is 7.11.7 running in a Docker Container (https://hub.docker.com/r/bitnami/suitecrm).

We’d be happy if anybody can help us with this issue.

Kind regards.

I don’t know, but that is a pretty large database…

Maybe it’s the MySQL engine that is consuming a lot of memory, and starves the other processes. But I am just guessing, perhaps you can try some MySQL diagnostics, and OS diagnostics.

I don’t think the indexing should necessarily take a lot of memory - it should just handle one record at a time. It could take a long time, a really long time, but I don’t see a reason why it should need a lot of memory.

Can you get me the full call stack of that FATAL error? So, it’s breaking in SugarBean.php, but who’s calling that? That might being some clues.

Thanks for the quick response.

We will try to identify possible memory issues when running the indexing as you suggested.

However we were not able to find any helpful information in SuiteCRM’s log file. When the level is set to “DEBUG” it’s just too big and flooded but setting it to “ERROR” or “FATAL” there were no obvious logs related to our indexing issue - but we will double check.

Regards

Have you checked also your web server log? It’s defined in your php.ini, it’s usually called php_errors.log or errors.log

If you can get that one, it might have additional clues, and it might have the call stack that I asked for.

Maybe the call stack needs to be turned on in some way. There’s an option in Admin / System Settings called “Display stack trace of errors:”, maybe turn that on. A stack trace is a numbered list that appears below the error, so for example your error

PHP Fatal error: Allowed memory size of 4294967296 bytes exhausted (tried to allocate 12288 bytes) in /bitnami/suitecrm/data/SugarBean.php on line 481
ERROR: Allowed memory size of 4294967296 bytes exhausted (tried to allocate 12288 bytes)
in /bitnami/suitecrm/data/SugarBean.php:481

should have some extra stuff below it

PHP Fatal error: Allowed memory size of 4294967296 bytes exhausted (tried to allocate 12288 bytes) in /bitnami/suitecrm/data/SugarBean.php on line 481
ERROR: Allowed memory size of 4294967296 bytes exhausted (tried to allocate 12288 bytes)
in /bitnami/suitecrm/data/SugarBean.php:481
#0 ...
#1 ....
#2 ....
#3. ...
#4 ....

I’m not sure but I think that it’s not actually possible to get a stack trace for a PHP Fatal Error.

But gladly I can give you an update on our problem. We’ve massively increased physical memory (8 GB) and made use of a swap file of 10 GB, and set

memory_limit = 12G

The indexing is currently running and will hopefully succeed :slight_smile:

Thanks for your help!

Another update:

root@afbf2ebc14d8:/bitnami/suitecrm# vendor/bin/robo -vvv elastic:index
[=][09:07:02] Starting indexing procedures
[@][09:07:02] Indexing is performed using JsonSerializerDocumentifier
[@][09:07:02] Reading lock file cache/ElasticSearchIndexer.lock
[@][09:07:02] Lock file not found
[@][09:07:02] A full indexing will be performed
[@][09:07:02] Removed index 'main'
[@][09:07:02] Loading mapping file /bitnami/suitecrm/lib/Search/ElasticSearch/defaultParams.yml
[@][09:07:02] Created new index 'main'
[@][09:09:56] Indexing module Accounts...
[@][09:24:18] Indexed 270076/270076 Accounts
PHP Fatal error:  Allowed memory size of 12884901888 bytes exhausted (tried to allocate 2853007200 bytes) in /bitnami/suitecrm/include/database/MysqliManager.php on line 139
ERROR: Allowed memory size of 12884901888 bytes exhausted (tried to allocate 2853007200 bytes)
in /bitnami/suitecrm/include/database/MysqliManager.php:139

270,000 accounts haven’t been a problem at all, the indexing happened in about 15 minutes.

It seems to have run out of memory loading the huge amount if 2.4 million contacts.

So, we tried the following things to get our contacts indexed:

  • Disabled MySQL slow query log (slow_query_log=0 in /etc/my.cnf)
  • Increased RAM from 4, to 8, to 20, to 45 GB
  • Increased swap file size from 10, to 20, to 25 GB

still resulting in

root@afbf2ebc14d8:/bitnami/suitecrm# vendor/bin/robo -vvv elastic:index
[=][12:34:55] Starting indexing procedures
[@][12:34:55] Indexing is performed using JsonSerializerDocumentifier
[@][12:34:55] Reading lock file cache/ElasticSearchIndexer.lock
[@][12:34:55] Lock file not found
[@][12:34:55] A full indexing will be performed
[@][12:34:55] Removed index 'main'
[@][12:34:55] Loading mapping file /bitnami/suitecrm/lib/Search/ElasticSearch/defaultParams.yml
[@][12:34:55] Created new index 'main'
[@][12:34:55] Indexing module Accounts...
[@][12:34:55] Indexed 60/60 Accounts
ERROR: Allowed memory size of 64424509440 bytes exhausted (tried to allocate 12288 bytes)
in /bitnami/suitecrm/data/SugarBean.php:481

Is it possible to index contacts in batches via CLI?

No there is no way to separate batches. I think we’re seeing a bug here, it shouldn’t accumulate stuff in memory, no matter how much indexing it has to do. So it would take a long time, but it shouldn’t break with a memory error.

I am a bit stuck, I don’t know what to tell you.

Have you considered if ElasticSearch would work better for you? It’s probably better at handling larger workloads.

Hi, thanks for your reply - it actually seems like a bug.

We could not make it work using SuiteCRM so we looked into the Elasticsearch document structure and wrote a custom PHP script to initially index (“full indexing”) all of our contacts.

It used a little less than 8 GB RAM and completed in about 15 minutes.

The Global Search now uses Elasticsearch (after configuring everything on the admin panel) but loading the contacts overview (list view) seems to be using MySQL and therefore taking between 1.5 and 2 minutes.
Any way to use Elasticsearch there as well?

This just came up on Github:

https://github.com/salesagility/SuiteCRM/issues/7886

By the way, can you share your custom script?

Also, I didn’t answer your question about the List view. I believe that the list view uses a paginated query and it shouldn’t take too long, even if you have a ton of records.

Can you turn on “log slow queries” in Admin / System settings and then scan your suitecrm.log to see which query is running long? If you’re using some custom filtering you might want to consider adding indexes to the database to speed that up, if appropriate.

The script does NOT consider any logic applied on Beans that SuiteCRM might apply when loading them. It really just fetches all contacts from the database and sends it to Elasticsearch’s Bulk API (using https://github.com/elastic/elasticsearch-php (Version: ^5.0) so be sure to install this dependency, e. g. via Composer).

<?php

ini_set('memory_limit', -1);

require_once __DIR__ . '/../vendor/autoload.php';

use Elasticsearch\ClientBuilder;

$suitePdo = new \PDO(
    'mysql:host='.$argv[1].';dbname='.$argv[2].';charset=utf8',
    $argv[3],
    $argv[4]
);

$contacts = $suitePdo->query(
    'SELECT c.id, c.date_entered, c.created_by, u1.user_name as created_user_name, c.date_modified, c.modified_user_id, u2.user_name as modified_user_name, c.assigned_user_id, u3.user_name as assigned_user_name, c.salutation, c.first_name, c.last_name, c.phone_other, c.primary_address_street, c.primary_address_city, c.primary_address_postalcode, c.primary_address_country, cc.account_number_c, ea.email_address
FROM contacts c
JOIN users u1 ON u1.id = c.created_by
JOIN users u2 ON u2.id = c.modified_user_id
JOIN users u3 ON u3.id = c.assigned_user_id
JOIN contacts_cstm cc ON cc.id_c = c.id
JOIN email_addr_bean_rel ear ON ear.bean_id = c.id
JOIN email_addresses ea ON ea.id = ear.email_address_id'
);

$elasticsearch = ClientBuilder::create()->setHosts([$argv[5]])->build();

$count = 1;

$contactsBatch = [];

foreach ($contacts->fetchAll(\PDO::FETCH_ASSOC) as $contact) {
    $contactsBatch['body'][] = [
        'index' => [
            '_index' => 'main',
            '_type' => 'Contacts',
            '_id' => $contact['id']
        ]
    ];

    $contactsBatch['body'][] = [
        'meta' => [
            'created' => [
                'date' => $contact['date_entered'],
                'user_id' => $contact['created_by'],
                'user_name' => $contact['created_user_name']
            ],
            'modified' => [
                'date' => $contact['date_modified'],
                'user_id' => $contact['modified_user_id'],
                'user_name' => $contact['modified_user_name']
            ],
            'assigned' => [
                'user_id' => $contact['assigned_user_id'],
                'user_name' => $contact['assigned_user_name']
            ],
            'name' => [
                'salutation' => $contact['salutation'],
                'first' => $contact['first_name'],
                'last' => $contact['last_name'],
                'name' => $contact['salutation'] . ' ' . $contact['first_name'] . ' ' . $contact['last_name'],
            ],
            'phone' => [
                'other' => $contact['phone_other']
            ],
            'address' => [
                'primary' => [
                    'street' => $contact['primary_address_street'],
                    'city' => $contact['primary_address_city'],
                    'postalcode' => $contact['primary_address_postalcode'],
                    'country' => $contact['primary_address_country']
                ]
            ],
            'account_number_c' => $contact['account_number_c'],
            'email' => [
                $contact['email_address']
            ]
        ]
    ];

    if ($count % 1000 == 0) {
        $responses = $elasticsearch->bulk($contactsBatch);

        // erase the old bulk request
        $contactsBatch = ['body' => []];

        // unset the bulk response when you are done to save memory
        unset($responses);

        echo 'Indexed ' . $count . ' Contacts...' . PHP_EOL;
    }

    $count++;
}

if (!empty($contactsBatch['body'])) {
    $responses = $elasticsearch->bulk($contactsBatch);
}

echo 'Indexed ' . $count . ' Contacts...' . PHP_EOL;

Usage:

php /path/to/script.php <suitecrm_db_host> <suitecrm_db_name> <suitecrm_db_user> <suitecrm_db_password> <elasticsearch_host>
1 Like

When slow query log is enabled:

Fri Sep 20 06:38:23 2019 [13751][1][FATAL] Slow Query (time:27.583695888519
 SELECT  contacts.id , contacts.assigned_user_id , LTRIM(RTRIM(CONCAT(IFNULL(contacts.first_name,''),' ',IFNULL(contacts.last_name,'')))) as name, contacts.first_name , contacts.last_name , contacts.salutation  , accounts.name account_name, jtl0.account_id account_id, contacts.title , contacts.phone_work  , jt1.user_name assigned_user_name , jt1.created_by assigned_user_name_owner  , 'Users' assigned_user_name_mod, contacts.date_entered , contacts.created_by  FROM contacts  LEFT JOIN contacts_cstm ON contacts.id = contacts_cstm.id_c   LEFT JOIN  accounts_contacts jtl0 ON contacts.id=jtl0.contact_id AND jtl0.deleted=0

 LEFT JOIN  accounts accounts ON accounts.id=jtl0.account_id AND accounts.deleted=0
 AND accounts.deleted=0  LEFT JOIN  users jt1 ON contacts.assigned_user_id=jt1.id AND jt1.deleted=0

 AND jt1.deleted=0 where contacts.deleted=0 ORDER BY contacts.date_entered ASC LIMIT 0,21)
Fri Sep 20 06:38:37 2019 [13751][1][FATAL] Slow Query (time:14.09875202179
 SELECT count(*) c FROM contacts  LEFT JOIN contacts_cstm ON contacts.id = contacts_cstm.id_c   LEFT JOIN  accounts_contacts jtl0 ON contacts.id=jtl0.contact_id AND jtl0.deleted=0

 LEFT JOIN  accounts accounts ON accounts.id=jtl0.account_id AND accounts.deleted=0
 AND accounts.deleted=0  LEFT JOIN  users jt1 ON contacts.assigned_user_id=jt1.id AND jt1.deleted=0

 AND jt1.deleted=0 where contacts.deleted=0)

For the second query, the “count”, there’s an option to turn all counts off in List views, this usually helps for large databases. See disable_count_query here: https://docs.suitecrm.com/developer/performance-tweaks/

For the first one, please check your database indexes to see. I’m not very knowledgeable on this subject, but for someone with good DBA skills this should be straight-forward.

Finally - are you sure your database hardware is up to the task? Ensure the server is not starved for resources (memory, CPU, disk throughput) given the dimension of your database.

Thanks for the script, I will have a look! This could be done with Beans (instead of direct SQL) by calling the paginated search (get_list) instead of the get_full_list (like the Elastic Search indexer currently does :frowning: ). But I think your approach is also ok, I don’t see any problems with it.

Thanks for your steady support on this.

Disabling the count query (disable_count_query = true) speeds up the contacts list (a bit) but I don’t see this is a “fix” but rather a workaround IMHO.

We looked into the query

SELECT contacts.id
    , contacts.assigned_user_id
    , LTRIM(RTRIM(CONCAT (
                IFNULL(contacts.first_name, '')
                , ' '
                , IFNULL(contacts.last_name, '')
                ))) AS name
    , contacts.first_name
    , contacts.last_name
    , contacts.salutation
    , accounts.name account_name
    , jtl0.account_id account_id
    , contacts.title
    , contacts.phone_work
    , jt1.user_name assigned_user_name
    , jt1.created_by assigned_user_name_owner
    , 'Users' assigned_user_name_mod
    , contacts.date_entered
    , contacts.created_by
FROM contacts
LEFT JOIN contacts_cstm ON contacts.id = contacts_cstm.id_c
LEFT JOIN accounts_contacts jtl0 ON contacts.id = jtl0.contact_id
    AND jtl0.deleted = 0
LEFT JOIN accounts accounts ON accounts.id = jtl0.account_id
    AND accounts.deleted = 0
    AND accounts.deleted = 0
LEFT JOIN users jt1 ON contacts.assigned_user_id = jt1.id
    AND jt1.deleted = 0
    AND jt1.deleted = 0
WHERE contacts.deleted = 0
ORDER BY contacts.date_entered ASC LIMIT 0, 21;

and found it might be enhanced dramatically by loading only the necessary contacts in the first place:

SELECT contacts.id
    , contacts.assigned_user_id
    , LTRIM(RTRIM(CONCAT (
                IFNULL(contacts.first_name, '')
                , ' '
                , IFNULL(contacts.last_name, '')
                ))) AS name
    , contacts.first_name
    , contacts.last_name
    , contacts.salutation
    , accounts.name account_name
    , jtl0.account_id account_id
    , contacts.title
    , contacts.phone_work
    , jt1.user_name assigned_user_name
    , jt1.created_by assigned_user_name_owner
    , 'Users' assigned_user_name_mod
    , contacts.date_entered
    , contacts.created_by
FROM (SELECT * FROM contacts WHERE contacts.deleted = 0 ORDER BY contacts.date_entered ASC LIMIT 0, 21) contacts 
LEFT JOIN contacts_cstm ON contacts.id = contacts_cstm.id_c
LEFT JOIN accounts_contacts jtl0 ON contacts.id = jtl0.contact_id
    AND jtl0.deleted = 0
LEFT JOIN accounts accounts ON accounts.id = jtl0.account_id
    AND accounts.deleted = 0
    AND accounts.deleted = 0
LEFT JOIN users jt1 ON contacts.assigned_user_id = jt1.id
    AND jt1.deleted = 0
    AND jt1.deleted = 0

Last query completes in < 10 milliseconds while the original one runs for about 30 seconds. I guess changing this would require some heavy changes in SuiteCRM’s source code.

We’ll check our VM’s hardware to make sure resources are not the cause here.

One more thing on the custom indexing script: Our only goal was to get all of our contacts into Elasticsearch so that we’re able to compare search speed between Elasticsearch and MySQL, so we didn’t really focus on handling/manipulating the data as SuiteCRM would before sending them to Elasticsearch.