Problem/Motivation

Code runs out of memory when entity indexing runs after deleting and creating about 5000 nodes.

After custom code has created all the nodes and saved the user, console starts to throw these warnings:

[warning] Could not load the following items on index Employees: "entity:user/49:en-x-simple", "entity:user/49:und", "entity:user/49:zxx", "entity:user/50:en-x-simple", "entity:user/50:und"......

After about 2000 warnings later, OOM happens:

PHP Fatal error: Allowed memory size of 1073741824 bytes exhausted (tried to allocate 20480 bytes) in /Users/myuser/www/docker-sites/some-drupal-site/web/core/lib/Drupal/Core/Field/FieldItemBase.php on line 109

Since the loop to create content in my code creates all the content and warnings start to appear after that, I suspect the error to be somewhere else.

Details about the issue

Site has a content type "contracts".
User has a multi-value entity reference field to the "contract".

Then there is a custom code, executed via Drush that fails with OOM:

  1. Deletes all content of a type "contract" (using the entityTypeManager, loadMultiple->delete()).
  2. LOOP STARTS to go through an array of data for contract creation
  3.   Creates contract (using Node::create())
  4.   Attaches contract to the user (by setting target_id on a user contract reference field)
  5.   Saves the user ($user->save())
  6.   All contracts are successfully created
  7. LOOP ENDS
  8. Now console starts showing these mentioned warnings
  9. With each warning memory usage increases
  10. After about 2000 warning messages, script dies with OOM error

I've added a quick memory usage dump to the place where the warning is coming from (file: web/modules/contrib/search_api/src/Entity/Index.php, line 903):

memory output

  • Memory usage when the first warning came: 385654 kB
  • Memory usage when the script failed: 1032739 kB
  • With each warning, memory usage increased around 3952 kB (+- 1000 kB).

Any ideas are appreciated and I'm open to help with debugging to trace it down.

Comments

adroid created an issue. See original summary.

adroid’s picture

Issue summary: View changes
david.muffley’s picture

I had a similar issue and I resolved it by resetting the cache of each indexed entity in PostRequestIndexing.php. My solution is just a bandaid to get past the issue I was having and has several holes in its implementation. Specifically it only resets the cache of the top-level indexed entities, any child entities that were loaded during the indexing action are not cleared. I'll attach it anyway as a starting point for further development.

drunken monkey’s picture

Component: General code » Framework
Status: Active » Needs review
StatusFileSize
new929 bytes

Thanks for reporting this problem!

If it’s custom code that is creating those items then a very simple solution would be to just call $search_api_index->startBatchTracking() at the start of the process, which prevents all the new items from being indexed in the same page request.

Also, we already have a very similar solution to #3 in our indexing code, namely at the bottom of \Drupal\search_api\Entity\Index::indexSpecificItems(). However, it currently only applies during indexing via Drush, but that could easily be changed – see the attached patch.
As only very few places in our code call this method, I think it should be safe to just do this generally. Worst case, some page request which do indexing in the middle (not at the end, with PostRequestIndexing) will be slowed down a bit – I think. No real way to be certain, I fear.

sonnykt’s picture

Status: Needs review » Reviewed & tested by the community

It seems that Drush detection in the issue #3036504 no longer works with both Drush 11 and 12.

    // When indexing via Drush, multiple iterations of a batch will happen in
    // the same PHP process, so the static cache will quickly fill up. To
    // prevent this, clear it after each batch of items gets indexed.
    if (function_exists('drush_backend_batch_process') && batch_get()) {
      \Drupal::getContainer()->get('entity.memory_cache')->deleteAll();
    }

When running cron with Drush 11/12, the memory usage keeps increasing and OOM is inevitable:

 [info] Starting execution of search_api_cron(), execution of scheduled_transitions_cron() took 1.67ms. [5.65 sec, 48.97 MB]
 [info] Indexed 20 items for index Classification Title. [5.93 sec, 54.54 MB]
 [info] Indexed 20 items for index Classification Title. [6.04 sec, 56.88 MB]
...

 [info] Indexed 20 items for index Classification Title. [12.76 sec, 218.94 MB]
 [info] Indexed 20 items for index Classification Title. [12.9 sec, 221.23 MB]
 [info] Indexed 20 items for index Classification Title. [12.97 sec, 223.53 MB]
 [info] Indexed 20 items for index Classification Title. [13.04 sec, 225.84 MB]

...
 [info] Indexed 20 items for index Classification Title. [19.74 sec, 354.88 MB]
 [info] Indexed 20 items for index Classification Title. [19.94 sec, 357.15 MB]
 [info] Indexed 20 items for index Classification Title. [20.01 sec, 359.45 MB]

PHP Fatal error:  Allowed memory size of 419430400 bytes exhausted (tried to allocate 20480 bytes) in /app/web/core/lib/Drupal/Core/Cache/CacheTagsChecksumTrait.php on line 131
PHP Fatal error:  Allowed memory size of 419430400 bytes exhausted (tried to allocate 32768 bytes) in /app/web/modules/contrib/shield/src/ShieldMiddleware.php on line 1

Applying the patch from #4 seems to fix the OOM issue.

 [info] Starting execution of search_api_cron(), execution of scheduled_transitions_cron() took 1.52ms. [4.86 sec, 49.08 MB]
 [info] Indexed 20 items for index Classification Title. [5.03 sec, 54.39 MB]
 [info] Indexed 20 items for index Classification Title. [5.12 sec, 54.92 MB]
 [info] Indexed 20 items for index Classification Title. [5.2 sec, 54.96 MB]
...

 [info] Indexed 20 items for index Classification Title. [9.8 sec, 56.54 MB]
 [info] Indexed 20 items for index Classification Title. [9.88 sec, 59.44 MB]
 [info] Indexed 20 items for index Classification Title. [9.96 sec, 56.48 MB]
...

 [info] Indexed 20 items for index Classification Title. [18.84 sec, 57.4 MB]
 [info] Indexed 20 items for index Classification Title. [18.92 sec, 60.31 MB]
 [info] Indexed 20 items for index Classification Title. [19.01 sec, 57.22 MB]
 [info] Starting execution of search_api_solr_cron(), execution of search_api_cron() took 14144.63ms. [19.01 sec, 57.22 MB]
 [info] Starting execution of simple_sitemap_cron(), execution of search_api_solr_cron() took 15.27ms. [19.03 sec, 57.9 MB]
sonnykt’s picture

  • drunken monkey committed c8a54141 on 8.x-1.x
    Issue #3321677 by drunken monkey, david.muffley: Fixed out-of-memory...
drunken monkey’s picture

Status: Reviewed & tested by the community » Fixed

Thanks for this additional information. If it also fixes Drush indexing, then I guess I’d really say we should go forward with it. “Normal” page requests should never index items during the request, anyways, so I don’t think there is a high potential for this breaking anything.

Merged. Thanks again, everyone!

Status: Fixed » Closed (fixed)

Automatically closed - issue fixed for 2 weeks with no activity.