[Django] #24743: Django 1.8.1 migrations are actually slower than 1.8?
Django
-------------------------------+--------------------
Reporter: pzrq | Owner: nobody
Type: Uncategorized | Status: new
Component: Migrations | Version: 1.8
Severity: Normal | Keywords:
Triage Stage: Unreviewed | Has patch: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------+--------------------
Ran `time ./manage.py test <a_project>.<a_fast_app>`, results:
1m25.611s
https://github.com/django/django/commit/2329ca969f81309bd3d15da55f25f8e1bee3122d
1m26.505s
https://github.com/django/django/commit/0cacb8f8ba94b06a78dcdfa22dc406a8a20a7f88
0m36.864s
https://github.com/django/django/commit/697317f3340b1d1f40586262098ad4dbae9aebaf
0m36.250s
https://github.com/django/django/commit/516907540b81c009b74d29b2fa36319b47528b49
1m6.195s
https://github.com/django/django/commit/43f800a978deba4bc8d13e7f11e0afdc126cec25
Some quick stats for our project - 134 models, 90 apps across 2 databases,
58 migrations in our django_migrations table (the bare minimum needed to
get us through Django 1.7 and 1.8).
Thought I'd put it out there and see if others are getting similar overall
slower results.
--
P.S. I don't really care either way what happens with ticket - take it,
close it, whatever. I was just surprised that the migrations ran more
slowly under 1.8.1 when the release notes suggested otherwise.
https://docs.djangoproject.com/en/1.8/releases/1.8.1/#optimizations
P.P.S. In practice migrations take sufficiently long relative to Django
1.6 that I've ended up building a `--ramdb` option into
https://github.com/pzrq/discover-road-runner which is why I don't really
care a great deal anymore - the second (and next dozen) times a 2s unit
test is run it takes around 2s instead of around one minute (to rerun the
migrations over again, I haven't checked if `--keepdb` has been updated
since the 1.8 beta to work with in-memory SQLite databases).
--
Ticket URL: <https://code.djangoproject.com/ticket/24743>
Django <https://code.djangoproject.com/>
The Web framework for perfectionists with deadlines.
Django
Reporter: pzrq | Owner: nobody
Type: Cleanup/optimization | Status: new
Component: Migrations | Version: 1.8
Severity: Release blocker | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
Changes (by timgraham):
* severity: Normal => Release blocker
* cc: MarkusH (added)
* needs_better_patch: => 0
* needs_tests: => 0
* needs_docs: => 0
* type: Uncategorized => Cleanup/optimization
* stage: Unreviewed => Accepted
Comment:
We should at least clarify the release notes, I suppose.
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:1>
Django
Reporter: pzrq | Owner: nobody
Type: Cleanup/optimization | Status: new
Component: Migrations | Version: 1.8
Severity: Release blocker | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by knbk):
* cc: marten.knbk@… (added)
Comment:
In the specific benchmark setup I'm running, the patch for #24573 triples
the amount of calls to `ModelState.render()`. That's quite a lot, and
explains why it is so much slower.
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:2>
Django
Reporter: pzrq | Owner: nobody
Type: Cleanup/optimization | Status: new
Component: Migrations | Version: 1.8
Severity: Release blocker | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by MarkusH):
I profiled the `executor.migrate()` call: https://dpaste.de/5hQH
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:3>
Django
Reporter: pzrq | Owner: nobody
Type: Cleanup/optimization | Status: new
Component: Migrations | Version: 1.8
Severity: Release blocker | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by MarkusH):
* Attachment "log.txt" added.
Django
Reporter: pzrq | Owner: nobody
Type: Cleanup/optimization | Status: new
Component: Migrations | Version: 1.8
Severity: Release blocker | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by timgraham):
Should we add this to the 1.8.1 release notes and remove the release
blocker flag?
{{{
#!diff
diff --git a/docs/releases/1.8.1.txt b/docs/releases/1.8.1.txt
index b9fc816..b01b09e 100644
--- a/docs/releases/1.8.1.txt
+++ b/docs/releases/1.8.1.txt
@@ -93,4 +93,5 @@ Optimizations
* Changed ``ModelState`` to deepcopy fields instead of deconstructing and
reconstructing (:ticket:`24591`). This speeds up the rendering of model
states and reduces memory usage when running :djadmin:`manage.py
migrate
- <migrate>`.
+ <migrate>` (although other changes in this release may negate any
performance
+ benefits).
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:4>
Django
Reporter: pzrq | Owner: nobody
Type: | Status: new
Cleanup/optimization |
Component: Migrations | Version: 1.8
Severity: Release blocker | Resolution:
Keywords: | Triage Stage: Ready for
| checkin
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by MarkusH):
* stage: Accepted => Ready for checkin
Comment:
Hey Tim, that looks reasonable to me.
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:5>
Django
Reporter: pzrq | Owner: nobody
Type: | Status: new
Cleanup/optimization |
Component: Migrations | Version: 1.8
Severity: Release blocker | Resolution:
Keywords: | Triage Stage: Ready for
| checkin
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by Tim Graham <timograham@…>):
In [changeset:"81d4ce4a6d21f0e65cabb253927770b3616cb560" 81d4ce4]:
{{{
#!CommitTicketReference repository=""
revision="81d4ce4a6d21f0e65cabb253927770b3616cb560"
Refs #24743 -- Clarified migrations performance note in 1.8.1 release
notes.
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:6>
Django
Reporter: pzrq | Owner: nobody
Type: | Status: new
Cleanup/optimization |
Component: Migrations | Version: 1.8
Severity: Release blocker | Resolution:
Keywords: | Triage Stage: Ready for
| checkin
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by Tim Graham <timograham@…>):
In [changeset:"7ea6477b3ad3a0da3196e5d3f5f09369e76c8cc5" 7ea6477]:
{{{
#!CommitTicketReference repository=""
revision="7ea6477b3ad3a0da3196e5d3f5f09369e76c8cc5"
[1.8.x] Refs #24743 -- Clarified migrations performance note in 1.8.1
release notes.
Backport of 81d4ce4a6d21f0e65cabb253927770b3616cb560 from master
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:7>
Django
Reporter: pzrq | Owner: nobody
Type: Cleanup/optimization | Status: new
Component: Migrations | Version: 1.8
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by timgraham):
* severity: Release blocker => Normal
* stage: Ready for checkin => Accepted
Comment:
Markus says he has an idea to improve performance here, so leaving the
ticket open.
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:8>
Django
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Component: Migrations | Version: 1.8
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by MarkusH):
* status: new => assigned
* owner: nobody => MarkusH
Comment:
I have an experimental / play PR that groups consecutive migrations that
need to be applied and only stores the state for the first of each of
them. This should drastically reduce the amount of used memory.
https://github.com/django/django/pull/4653
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:9>
Django
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by petersanchez):
Has anyone tested the PR yet? I haven't had a chance to yet. Upgrading a
larger project from 1.7.x to 1.8.2 has migrations running very slow. See
output here (note, this is on my MacBook Air, PG9, etc.):
{{{
(env)macbook ~/development/houselogic/src/houselogic $ time ./manage.py
migrate --fake-initial
Operations to perform:
Synchronize unmigrated apps: google, rendertext, allauth, twitter,
linkedin, django_extensions, typogrify, django_mobile, audioplayer,
tinymce, cumulus, humanize, haystack, thumbnail, mptt, staticfiles,
sitemaps, facebook, edialog, pipeline, sitecatalyst, messages,
syndication, social_media
Apply all migrations: redirects, openid, realtors, accounts,
user_content, editorial_content, badges, layout, buying_selling, sites,
comments, blog, contenttypes, work_queue, sweepstakes, main, core,
django_comments, sessions, faq, auth, binder, news, account, admin,
contest, modules, recommendations, twitter_logger, socialaccount
Synchronizing apps without migrations:
Creating tables...
Running deferred SQL...
Installing custom SQL...
Running migrations:
Rendering model states... DONE
Applying account.0001_initial... FAKED
Applying account.0002_email_max_length... OK
Applying accounts.0004_auto_20150615_1533... OK
Applying auth.0003_auto_20150615_1533... OK
Applying badges.0003_auto_20150615_1533... OK
Applying django_comments.0002_update_user_email_field_length... OK
Applying blog.0004_auto_20150615_1533... OK
Applying buying_selling.0004_auto_20150615_1533... OK
Applying contenttypes.0002_remove_content_type_name... OK
Applying django_comments.0003_auto_20141110_1644... OK
Applying editorial_content.0007_auto_20150528_2042... OK
Applying editorial_content.0008_video_source... OK
Applying editorial_content.0009_navigationcategoryfeaturedlink_video...
OK
Applying editorial_content.0010_auto_20150618_1845... OK
Applying editorial_content.0010_auto_20150615_1533... OK
Applying editorial_content.0011_merge... OK
Applying layout.0004_homepagecarouselitem_video... OK
Applying layout.0005_auto_20150611_2216... OK
Applying modules.0003_auto_20150615_1533... OK
Applying news.0002_auto_20150615_1533... OK
Applying openid.0001_initial... FAKED
Applying realtors.0003_auto_20150615_1533... OK
Applying socialaccount.0001_initial... FAKED
real 7m4.016s
user 6m48.144s
sys 0m3.732s
}}}
The "Rendering model states" piece takes the longest. Over 5 minutes.
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:10>
Django
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by acdha):
* cc: chris@… (added)
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:11>
Django
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by hugotacito):
Like petersanchez, I was upgrading a big project from 1.7.x to 1.8.2 .
MacBook Air here too. Our project has
1900 ForeignKeyFields, 300 ManyToManyFields, 750 Models and 42 modules.
It took me 93 minutes just to render model states for the first time.
'''Operations to perform:'''
'''Synchronize unmigrated apps:''' pagination, ckeditor, staticfiles,
rest_framework_swagger, django_extensions, django_tables2, djtools,
rest_framework, django_tables2_reports
'''Apply all migrations:''' projetos, ae, ponto, frota, enquete, edu,
financeiro, arquivo, patrimonio, estacionamento, authtoken, materiais,
convenios, contratos, comum, contenttypes, remanejamento, almoxarifado,
temp_ideias, rh, contracheques, protocolo, sessions, chaves, progressoes,
auth, eleicao, cnpq, rsc, centralservicos, ldap_backend,
processo_seletivo, admin, cpa, gestao, compras, orcamento, cursos, pdi,
ferias, planejamento, microsoft
'''Synchronizing apps without migrations:'''
...
'''Running migrations:'''
Rendering model states... DONE (5554.627s)
Applying ae.0006_auto_20150619_1253... OK (26.600s)
...
After that I ran a new migration and the rendering model states dropped to
11 seconds.
'''Operations to perform:'''
'''Synchronize unmigrated apps:''' pagination, ckeditor, staticfiles,
rest_framework_swagger, django_extensions, django_tables2, djtools,
rest_framework, django_tables2_reports
'''Apply all migrations:''' projetos, ae, ponto, frota, enquete, edu,
financeiro, arquivo, patrimonio, estacionamento, authtoken, materiais,
convenios, contratos, comum, contenttypes, remanejamento, almoxarifado,
temp_ideias, rh, contracheques, protocolo, sessions, chaves, progressoes,
auth, eleicao, cnpq, rsc, centralservicos, ldap_backend,
processo_seletivo, admin, cpa, gestao, compras, orcamento, cursos, pdi,
ferias, planejamento, microsoft
'''Synchronizing apps without migrations:'''
...
'''Running migrations:'''
Rendering model states... DONE (11.538s)
Applying edu.0028_historicoimportacao_alunos_afetados... OK (5.851s)
...
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:12>
Django
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by etanol):
We also experience a noticeable increase in the ''rendering model state''
step. Apparently, the most expensive operation is `AddField` even when
running only in ''state mutation'' mode.
The attached profile results can be inspected by running `python -m pstats
migrate2.pstats`.
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:13>
Django
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by etanol):
* Attachment "migrate2.pstats.gz" added.
Profiled run of command migrate
Django
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by mjacksonw):
* cc: mjacksonw (added)
Comment:
We've been frustrated by this issue since 1.8 hit, seeing the same impacts
as previous posters – the "Rendering model states" step taking several
minutes when running fresh, which most notably impacts our testing
environments.
Our current "workaround," if you can call it that, is skipping migrations
in testing except when testing our master branch, and squashing migrations
as much as possible. Still, more than half of the time it takes to run our
tests is consumed by this "Rendering model states" step.
I tossed in MarkusH's PR (mentioned in comment:9) this morning, and ran
`migrate` against a fresh database three times against stock 1.8.3, and
three times with the changes from the PR:
1.8.3 – Min: 4m56s, Max: 5m32s, Avg: 5m26s
PR – Min: 32s, Max: 39s, Avg: 34s
Specifically, the Rendering models states step went from about 4.5 mins to
three or four seconds.
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:14>
Django
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by MarkusH):
Thank you etanol! Here is the output of the first rows sorted by
"cumtime". This clearly shows (from my perspective) a high expense in the
model's meta class: `django/db/models/base.py:72(__new__)`
{{{
1538924506 function calls (1535110811 primitive calls) in
1483.255 seconds
Ordered by: cumulative time
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 1483.272 1483.272
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/core/management/base.py:369(run_from_argv)
16/1 0.001 0.000 1483.270 1483.270
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/core/management/base.py:404(execute)
1 0.008 0.008 1482.956 1482.956
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/core/management/commands/migrate.py:55(handle)
1 0.003 0.003 1473.721 1473.721
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/migrations/executor.py:65(migrate)
1809 0.501 0.000 1471.618 0.813
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/migrations/state.py:91(reload_model)
148 0.008 0.000 1468.430 9.922
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/migrations/migration.py:72(mutate_state)
1536 0.610 0.000 1441.001 0.938
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/migrations/state.py:252(render_multiple)
239262 8.476 0.000 1440.390 0.006
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/migrations/state.py:520(render)
1352 0.058 0.000 1124.941 0.832
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/migrations/operations/fields.py:43(state_forwards)
300486/239262 13.254 0.000 834.475 0.003
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/models/base.py:72(__new__)
4083939 21.946 0.000 595.130 0.000
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/migrations/state.py:488(construct_fields)
300486 1.486 0.000 498.434 0.002
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/migrations/state.py:285(register_model)
302024 29.834 0.000 496.382 0.002
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/apps/registry.py:334(clear_cache)
40673088 270.223 0.000 388.286 0.000
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/models/options.py:711(_expire_cache)
5237503/4808935 7.485 0.000 320.286 0.000
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/models/base.py:321(add_to_class)
734946 2.335 0.000 263.046 0.000
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/utils/lru_cache.py:94(wrapper)
522243 40.921 0.000 255.000 0.000
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/apps/registry.py:153(get_models)
430612 81.365 0.000 240.780 0.001
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/models/fields/related.py:309(swappable_setting)
369388 1.661 0.000 232.581 0.001
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/models/fields/related.py:1867(deconstruct)
369388 2.692 0.000 230.388 0.001
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/models/fields/related.py:1551(deconstruct)
105539832 90.430 0.000 200.647 0.000
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/apps/config.py:164(get_models)
233 0.012 0.000 197.541 0.848
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/migrations/operations/fields.py:172(state_forwards)
3844735 113.134 0.000 176.851 0.000
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/models/fields/__init__.py:358(deconstruct)
61224 0.902 0.000 170.041 0.003
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/models/fields/related.py:2518(contribute_to_class)
61224 3.381 0.000 161.656 0.003
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/models/fields/related.py:2048(create_many_to_many_intermediary_model)
314498387 110.460 0.000 110.460 0.000 {delattr}
115 0.006 0.000 106.834 0.929
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/migrations/operations/models.py:519(state_forwards)
21800334 69.904 0.000 106.573 0.000
/usr/lib/python2.7/collections.py:104(values)
4028349 7.703 0.000 105.095 0.000
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/models/fields/__init__.py:655(contribute_to_class)
4028349 11.031 0.000 72.275 0.000
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/models/options.py:289(add_field)
300486 3.620 0.000 72.108 0.000
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/models/base.py:328(_prepare)
4032533 53.182 0.000 71.715 0.000
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/models/fields/__init__.py:137(__init__)
1686026 13.135 0.000 64.277 0.000
/home/isaac/virtualenvs/bookcore/local/lib/python2.7/site-
packages/django/db/models/fields/__init__.py:1080(__init__)
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:15>
Django
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by MarkusH):
I rebased the current implementation onto the recent master in a new PR:
https://github.com/django/django/pull/5125
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:16>
Django
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by MarkusH):
I thought about giving the rendering another improvement, but before
diving in I ran cProfile on the `rendering model states` phase on the
current stable/1.8.x branch (0e3a8c22dfbbe06a9a81afb2593255293efdc87e) and
master (97ac77e544f9b1d1f28c0f859bef8fbc195d81a5) with the following diff
applied:
{{{#!diff
diff --git a/django/core/management/commands/migrate.py
b/django/core/management/commands/migrate.py
index d26fd3d..40dca0b 100644
--- a/django/core/management/commands/migrate.py
+++ b/django/core/management/commands/migrate.py
@@ -219,7 +219,9 @@ class Command(BaseCommand):
else:
fake = options.get("fake")
fake_initial = options.get("fake_initial")
- executor.migrate(targets, plan, fake=fake,
fake_initial=fake_initial)
+ import cProfile
+ cProfile.runctx('executor.migrate(targets, plan, fake=fake,
fake_initial=fake_initial)', globals(), locals(),
filename='/tmp/stats.pstats')
+ # executor.migrate(targets, plan, fake=fake,
fake_initial=fake_initial)
# Send the post_migrate signal, so individual apps can do
whatever they need
# to do at this point.
diff --git a/django/db/migrations/executor.py
b/django/db/migrations/executor.py
index aeb021e..2c08ab3 100644
--- a/django/db/migrations/executor.py
+++ b/django/db/migrations/executor.py
@@ -104,6 +104,7 @@ class MigrationExecutor(object):
state = migration.mutate_state(state, preserve=do_run)
if self.progress_callback:
self.progress_callback("render_success")
+ return
# Phase 2 -- Run the migrations
for migration, backwards in plan:
if not backwards:
}}}
This yield the attached pstats files with my "benchmark" repository
https://github.com/MarkusH/django-migrations-benchmark. I put the output
of the first ~40 rows into a gist (better readability):
https://gist.github.com/MarkusH/0c5d30449cdf7f1961f6 . What one can see is
a reduction by almost 50%.
Can somebody confirm this improvement in one of their real world projects,
please.
This is on Python 3.4.3 on ArchLinux
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:17>
Django
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by MarkusH):
* Attachment "stats-1.8.4.pstats" added.
Django
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by MarkusH):
* Attachment "stats-master.pstats" added.
Django
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by MarkusH):
Here's another approach that partly goes back to the old behavior:
https://github.com/django/django/pull/5178
Could you all please run your migrations on that pull request and give
some feedback.
At least forwards migrations should be faster.
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:18>
Django
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
Changes (by MarkusH):
* needs_docs: 0 => 1
* has_patch: 0 => 1
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:19>
Django
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 1
Easy pickings: 0 | UI/UX: 0
Comment (by hugotacito):
Hello markush, the first PR: https://github.com/django/django/pull/5125
didn't improved the speed... I'm gonna test asap the other PR, but the
problem is that the test takes a long time. And I have to run on an idle
machine to not impact in results.
{{{
-> % time python -m cProfile -o migrate2.pstats manage.py migrate -v 3
Operations to perform:
Synchronize unmigrated apps: pagination, ckeditor, staticfiles,
rest_framework_swagger, django_extensions, django_tables2, saude, djtools,
rest_framework, django_tables2_reports
Apply all migrations: projetos, ae, ...
Synchronizing apps without migrations:
Running pre-migrate handlers for application auth
Running pre-migrate handlers for application contenttypes
Running pre-migrate handlers for application sessions
Running pre-migrate handlers for application djtools
Running pre-migrate handlers for application admin
...
Creating tables...
Running deferred SQL...
Installing custom SQL...
Loading 'initial_data' fixtures...
Checking '/Users/hugo/workspace/suap' for fixtures...
No fixture 'initial_data' in '/Users/hugo/workspace/suap'.
...
Running migrations:
Rendering model states... DONE (7598.382s)
Applying ae.0009_auto_20150819_1451... OK (32.787s)
Applying arquivo.0004_auto_20150819_1451... OK (5.327s)
Applying contenttypes.0002_remove_content_type_name... OK (14.731s)
Applying auth.0002_alter_permission_name_max_length... OK (4.936s)
Applying auth.0003_alter_user_email_max_length... OK (5.118s)
Applying auth.0004_alter_user_username_opts... OK (5.106s)
Applying auth.0005_alter_user_last_login_null... OK (6.599s)
Applying auth.0006_require_contenttypes_0002... OK (0.015s)
...
Running post-migrate handlers for application auth
Running post-migrate handlers for application contenttypes
Running post-migrate handlers for application sessions
Running post-migrate handlers for application djtools
Running post-migrate handlers for application admin
...
python -m cProfile -o migrate3.pstats manage.py migrate -v 3
7671.55s user
93.25s system
92% cpu
2:20:36.92 total
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:20>
Django
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 1
Easy pickings: 0 | UI/UX: 0
Comment (by hugotacito):
Unfortunatly the pstat file was too big to fit in this ticket system so I
uploaded it to dropbox
https://www.dropbox.com/s/x22vjeog1ev1bdv/migrate3.pstats.gz?dl=0
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:21>
Django
--------------------------------------+------------------------------------
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Component: Migrations | Version: 1.8
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 1
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
--------------------------------------+------------------------------------
Comment (by hugotacito):
The PR https://github.com/django/django/pull/5178 dropped down the
Rendering model states to 5 seconds in my project. But at some point the
migrations freeze (usually when goes to execute the migrations from a
third module).
PS: My project is not compliant with django 1.9 yet, so i copied the
content from the PR to django 1.8.4. Probably thats the problem with the
freezing.
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:22>
Django
--------------------------------------+------------------------------------
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Component: Migrations | Version: 1.8
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 1
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
--------------------------------------+------------------------------------
Comment (by MarkusH):
What do you mean with "freeze"? Endless loop? Running for some time and it
gets slower?
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:23>
Django
--------------------------------------+------------------------------------
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Component: Migrations | Version: 1.8
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 1
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
--------------------------------------+------------------------------------
Comment (by hugotacito):
Hello markus, after running for some time it gets very slower (like 5
minutes) in between the change of modules. It doesn't go to endless loop.
Example:
Applying financial.0007_auto_20150819_1451... OK (24.984s)
'''(long wait)'''
Applying fleet.0004_auto_20150819_1451... OK (17.156s)
'''(long wait)'''
Applying parking.0004_auto_20150819_1451... OK (11.604s)
'''(long wait)'''
Applying poll.0014_auto_20150805_1413... OK (9.664s)
Applying poll.0015_auto_20150819_1451... OK (34.831s)
'''(long wait)'''
Applying protocol.0003_auto_20150819_1451... OK (10.068s)
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:24>
Django
--------------------------------------+------------------------------------
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Component: Migrations | Version: 1.8
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 1
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
--------------------------------------+------------------------------------
Comment (by hugotacito):
The pstat file:
https://www.dropbox.com/s/c18k409qvwgn2bl/migrate4.pstats.gz?dl=0
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:25>
Django
--------------------------------------+------------------------------------
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Component: Migrations | Version: 1.8
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 1
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
--------------------------------------+------------------------------------
Comment (by Markus Holtermann <info@…>):
In [changeset:"e1427cc609fa6ab247501b101cfb3c0092aba55b" e1427cc6]:
{{{
#!CommitTicketReference repository=""
revision="e1427cc609fa6ab247501b101cfb3c0092aba55b"
Fixed #24590 -- Cached calls to swappable_setting.
Moved the lookup in Field.swappable_setting to Apps, and added
an lru_cache to cache the results.
Refs #24743
Thanks Marten Kenbeek for the initial work on the patch. Thanks Aymeric
Augustin and Tim Graham for the review.
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:26>
Django
--------------------------------------+------------------------------------
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Component: Migrations | Version: 1.8
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 1
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
--------------------------------------+------------------------------------
Comment (by prophile):
For what it's worth, this patch greatly improved model state rendering for
us:
{{{
diff -r /tmp/saved-django/db/migrations/executor.py
contrib/django/db/migrations/executor.py
99,100d98
< if 'apps' not in state.__dict__:
< state.apps # Render all real_apps -- performance
critical
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:27>
Django
--------------------------------------+------------------------------------
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Component: Migrations | Version: 1.8
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 1
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
--------------------------------------+------------------------------------
Comment (by MarkusH):
Replying to [comment:27 prophile]:
> For what it's worth, this patch greatly improved model state rendering
for us:
>
> {{{
> diff -r /tmp/saved-django/db/migrations/executor.py
contrib/django/db/migrations/executor.py
> 99,100d98
> < if 'apps' not in state.__dict__:
> < state.apps # Render all real_apps -- performance
critical
> }}}
Not really, it just delays the rendering.
The `Rendering model state` will be faster, yes. But instead of rendering
the models there, Django will render them when applying the migrations. At
that phase it might even look like migrations are stuck.
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:28>
Django
--------------------------------------+------------------------------------
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Component: Migrations | Version: 1.8
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 1
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
--------------------------------------+------------------------------------
Comment (by mjacksonw):
Replying to [comment:18 MarkusH]:
> Here's another approach that partly goes back to the old behavior:
https://github.com/django/django/pull/5178
>
> Could you all please run your migrations on that pull request and give
some feedback.
Yup, brings the "rendering model states" step down to practically zero,
and no obvious side effects or other unexpected impacts. Looking forward
to this!
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:29>
Django
--------------------------------------+------------------------------------
Reporter: pzrq | Owner: MarkusH
Type: Cleanup/optimization | Status: assigned
Component: Migrations | Version: 1.8
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 1
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
--------------------------------------+------------------------------------
Comment (by pzrq):
Replying to [comment:29 mjacksonw]:
> Replying to [comment:18 MarkusH]:
> > Here's another approach that partly goes back to the old behavior:
https://github.com/django/django/pull/5178
> >
> > Could you all please run your migrations on that pull request and give
some feedback.
>
> Yup, brings the "rendering model states" step down to practically zero,
and no obvious side effects or other unexpected impacts. Looking forward
to this!
+1 here - hope it makes it into Django 1.9 and gives people more good
reasons to upgrade.
I backported (poorly, though it's a reasonably clean cherry-pick in just
bringing in some extra unused 1.9 stuff) to 1.8.x:
https://github.com/pzrq/django/compare/stable/1.8.x...backport_for_test_24743
With that I get a >50% speedup from 5m59.611s to 2m54.410s when running
the built in `time ./manage.py test <a_project>.<a_fast_app>`. Not
comparable to the originally reported timings as we've added a lot of
migrations, but a very welcome speedup either way :)
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:30>
Django
Reporter: pzrq | Owner: MarkusH
Type: | Status: assigned
Cleanup/optimization |
Component: Migrations | Version: 1.8
Severity: Normal | Resolution:
| checkin
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
Changes (by timgraham):
* needs_docs: 1 => 0
* stage: Accepted => Ready for checkin
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:31>
Django
-------------------------------------+-------------------------------------
Reporter: pzrq | Owner: MarkusH
Cleanup/optimization |
Component: Migrations | Version: 1.8
Keywords: | Triage Stage: Ready for
| checkin
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
* status: assigned => closed
* resolution: => fixed
Comment:
In [changeset:"5aa55038ca9ac44b440b56d1fc4e79c876e51393" 5aa55038]:
{{{
#!CommitTicketReference repository=""
revision="5aa55038ca9ac44b440b56d1fc4e79c876e51393"
Fixed #24743, #24745 -- Optimized migration plan handling
The change partly goes back to the old behavior for forwards migrations
which should reduce the amount of memory consumption (#24745). However,
by the way the current state computation is done (there is no
`state_backwards` on a migration class) this change cannot be applied to
backwards migrations. Hence rolling back migrations still requires the
precomputation and storage of the intermediate migration states.
This improvement also implies that Django does not handle mixed
migration plans anymore. Mixed plans consist of a list of migrations
where some are being applied and others are being unapplied.
Thanks Andrew Godwin, Josh Smeaton and Tim Graham for the review as well
as everybody involved on the ticket that kept me looking into the issue.
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/24743#comment:32>