#22608 (Migrations optimizer slow (due to double working?)) – Django (original) (raw)

#22608 closed Cleanup/optimization (duplicate)

makemigrations is currently fairly conservative with splitting operations into separate migrations, e.g. when there are fk dependencies. after manually merging some of these i noticed a significant speedup, which surprised andrewgodwin

did some basic profiling and it looks like many smaller migration need to re-do some work. will try to look more into this, but wanted to raise a ticket to track

separate:
38 migrations over 9 apps (3, 14, 6, 3, 1, 1, 5, 2, 3)

profiling ./manage.py test app1 around executor.migrate(targets, plan, fake=options.get("fake", False))

     17353606 function calls (17308702 primitive calls) in 39.818 seconds

Ordered by: internal time List reduced from 505 to 10 due to restriction <10>

ncalls tottime percall cumtime percall filename:lineno(function) 152757 7.436 0.000 12.352 0.000 /Users/david/dev/django_source/django/db/models/fields/init.py:290(deconstruct) 155191 3.989 0.000 5.518 0.000 /Users/david/dev/django_source/django/db/models/fields/init.py:121(init) 22617 3.125 0.000 4.428 0.000 /Users/david/dev/django_source/django/db/models/fields/related.py:276(swappable_setting) 4561050/4537097 2.817 0.000 2.843 0.000 {getattr} 419 2.477 0.006 2.478 0.006 {method 'execute' of 'psycopg2._psycopg.cursor' objects} 16993 1.477 0.000 27.452 0.002 /Users/david/dev/django_source/django/db/migrations/state.py:229(clone) 12854 0.833 0.000 1.117 0.000 /usr/local/Cellar/python/2.7.3/Frameworks/Python.framework/Versions/2.7/lib/python2.7/collections.py:37(init) 852604/852602 0.796 0.000 1.643 0.000 {isinstance} 1558116 0.706 0.000 0.882 0.000 /Users/david/dev/django_source/django/db/models/options.py:282(_swapped) 3124169 0.655 0.000 0.666 0.000 {method 'get' of 'dict' objects}

manually merged into 1 migration per app:

     3650282 function calls (3640151 primitive calls) in 9.895 seconds

Ordered by: internal time List reduced from 495 to 10 due to restriction <10>

ncalls tottime percall cumtime percall filename:lineno(function) 321 0.959 0.003 0.959 0.003 {method 'execute' of 'psycopg2._psycopg.cursor' objects} 19363 0.898 0.000 1.646 0.000 /Users/david/dev/django_source/django/db/models/fields/init.py:290(deconstruct) 20870 0.648 0.000 0.874 0.000 /Users/david/dev/django_source/django/db/models/fields/init.py:121(init) 3236 0.432 0.000 0.656 0.000 /Users/david/dev/django_source/django/db/models/fields/related.py:276(swappable_setting) 642018/638002 0.427 0.000 0.432 0.000 {getattr} 32654 0.331 0.000 0.331 0.000 {method 'items' of 'dict' objects} 5662 0.286 0.000 0.286 0.000 /Users/david/dev/django_source/django/db/models/base.py:34(subclass_exception) 6823 0.232 0.000 0.232 0.000 /Users/david/dev/django_source/django/utils/functional.py:15(curry) 180384 0.230 0.000 0.230 0.000 {hasattr} 3673 0.225 0.000 0.511 0.000 /Users/david/dev/django_source/django/db/models/fields/related.py:1584(init)

Change History(27)

comment:7 by Claude Paroz, 11 years ago

On my system, I realized that each migration added to the Django test suite adds up 3.5 sec. to the initial test database initialization (both with SQLite and PostgreSQL).

comment:8 by Claude Paroz, 11 years ago

In my profiling, I found that the most costly is rendering of the whole project state, at least two times for each migration, once for MigrationExecutor.detect_soft_applied and one or two times in Operation.database_forwards (27.5 secs cum time for 17 calls in Django's test suite, 8 migrations).
Andrew, it would be interesting to know if you tried to optimize this, and particularly if ProjectState.apps could be reused/mutated or if this is a lost battle.

comment:10 by Claude Paroz, 11 years ago

comment:11 by Claude Paroz, 11 years ago

Slowness about the migrate process itself is separately tracked in #23745.

comment:13 by Ulrich Petri, 10 years ago

This PR ​https://github.com/django/django/pull/3545 speeds up the optimizer by about 60% simply by pulling out the creation of two utility lists from function to module scope and caching the result of calling .lower() on the .name, .old_name, .new_name and .module_name attributes in Operation subclasses.

comment:14 by Collin Anderson, 10 years ago

comment:16 by Markus Holtermann, 10 years ago

comment:19 by Tim Graham, 10 years ago

Committed the PR, but no doubt more work can be done on this so leaving the ticket open.

comment:20 by Claude Paroz, 10 years ago

It would be nice to get an up-to-date profiling report with a big project to know the progress done with recent commits.

comment:26 by Claude Paroz, 7 years ago

Note: See TracTickets for help on using tickets.