Slow migration process when migrating nested field collections

Question

I'm migrating a site with something like 2000 nodes each having some field collections with other field collections nested in them. Basically, example node looks like this:

              level 1                 level 2
node -> field collection[0] ->  field collection[0] -> fields
     |                      |-> field collection[1] -> fields
     |                      |-> field collection[2] -> fields
     |
     -> field collection[1] -> field collection[0] -> fields
                            |-> field collection[1] -> fields
                            |-> field collection[2] -> fields
                            |-> field collection[3] -> fields
                            |-> field collection[4] -> fields

So, each node can have one or more level 1 field collections and each level 1 collection can have one or more level 2 collections.

My migration procedure was to first migrate nodes, then level 1 collections and now I'm migrating level 2 collections. Everything seems to work fine but when I got to level 2 import, the migration process slowed down to a crawl: close to one field collection entity per second!

This is insane! I've checked the queries that are being run during migration and it turned out that each migrated collection triggers a query that looks like this:

INSERT INTO field_data_field_level_2 (
    entity_type, entity_id, revision_id, bundle, delta, language,
    field_level_2_value, field_level_2_revision_id)
VALUES
    ('field_collection_item', '1486', '1486', 'field_level_1', '0', 'und', '3626', '3626'),
    ('field_collection_item', '1486', '1486', 'field_level_1', '1', 'und', '3627', '3627'),
    ('field_collection_item', '1486', '1486', 'field_level_1', '2', 'und', '3628', '3628'),
    ('field_collection_item', '1486', '1486', 'field_level_1', '3', 'und', '3629', '3629'),
    ...
    ...

The list goes on and on up to hundreds of rows! And it is increasing with each imported field collection. This is insane. How to optimize that?

The data is imported from other database, so map_joinable is set to false - could this be the reason? But why? It looks like for each import some rows are deleted and then saved again.

I've ran the import process with --instrument switch and got these results:

Name                Cum (bytes)  Count  Avg (bytes)
 destination import  51215952     100    512160
 Timer                                              Cum (sec)  Count  Avg (msec)
 page                                               424.547    1      424547.19
 destination import                                 421.709    100    4217.089
 field_collection_save                              418.984    100    4189.84
 saveIDMapping                                      0.948      100    9.484
 mapRowBySource                                     0.716      2204   0.325
 MigrateFieldsEntityHandler->prepare                0.27       100    2.704
 lookupDestinationID                                0.1        200    0.5
 MigrateDestinationEntity->prepareFields            0.061      100    0.613
 MigrateFieldsEntityHandler->complete               0.043      100    0.428
 MigrateDestinationEntity->completeFields           0.038      100    0.375
 MigrateValueFieldHandler->prepare                  0.008      200    0.042
 MigrateSourceSQL performRewind                     0.007      1      7.2
 MigrateSourceSQL execute                           0.007      1      7.11
 MigratePathEntityHandler->prepare                  0.006      100    0.059
 MigrateTaxonomyTermReferenceFieldHandler->prepare  0.004      100    0.044
 MigrateSourceSQL getNextRow                        0.004      100    0.041
 VildmedmadIngredientMigration prepareRow           0.003      100    0.035

I don't know what 'page' timer is but field_collection_save timer looks very suspicious.

[edit]

Similar issues happens when I do rollback. Same insane queries inserting lots of rows into field_data_field_level_2 table for each removed filed collection. Here's weird thing though: I would expect that the rollback is slow at the beginning and speeds up when there is less rows to work with. But no! It started very fast and slowed down over time.

Answer 1

For those facing similar problem: the issue was caused by one node that had 3000+ level 2 field collections. This was caused by a malformed source data. After fixing this, the largest level 2 field collection set was roughly 50 entities and that worked fine. No slowdowns.

The problem with 3000+ field collections working slow was caused by entity_save that each time sent that humongous query to the database. It basically meant that each newly added field collection resulted in a query that contained all of the field collections for that particular entity.

This is insane, but that's how it works inside entity_save. The only workaround for that seems to be manually creating those entities or maybe even writing custom entity controller. Fortunately I didn't have to do that - fixing source data relationships solved the problem.