OOM issue after creating approx 5000 nodes

Created on 15 November 2022, over 1 year ago
Updated 11 November 2023, 8 months ago

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 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.

πŸ› Bug report
Status

Fixed

Version

1.23

Component

Framework

Created by

πŸ‡ͺπŸ‡ͺEstonia adroid

Live updates comments and jobs are added and updated live.
Sign in to follow issues

Comments & Activities

Not all content is available!

It's likely this issue predates Contrib.social: some issue and comment data are missing.

  • 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.

  • Status changed to Needs review about 1 year ago
  • Open in Jenkins β†’ Open on Drupal.org β†’
    Core: 9.5.x + Environment: PHP 8.1 & sqlite-3.27
    last update about 1 year ago
    536 pass
  • πŸ‡¦πŸ‡ΉAustria drunken monkey Vienna, Austria

    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.

  • Open in Jenkins β†’ Open on Drupal.org β†’
    Core: 9.5.x + Environment: PHP 8.1 & MySQL 5.7
    last update about 1 year ago
    539 pass
  • Status changed to RTBC 8 months ago
  • Open in Jenkins β†’ Open on Drupal.org β†’
    Core: 9.5.x + Environment: PHP 8.1 & sqlite-3.27
    last update 8 months ago
    545 pass
  • πŸ‡¦πŸ‡ΊAustralia sonnykt Melbourne, Australia

    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 πŸ› OOM issue after creating approx 5000 nodes Needs review 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]
    
  • πŸ‡¦πŸ‡ΊAustralia sonnykt Melbourne, Australia
  • Status changed to Fixed 8 months ago
  • πŸ‡¦πŸ‡ΉAustria drunken monkey Vienna, Austria

    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!

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

Production build 0.69.0 2024