id summary reporter owner description type status component version severity resolution keywords cc stage has_patch needs_docs needs_tests needs_better_patch easy ui_ux 27279 Performance regression when running migrate with RenameModel operations mtomiyoshi Simon Charette "Since I upgraded to 1.10.1 I've been seeing much slower test initialization than before. There is no noticeable difference afterwards, but when running just a small subset of tests the slow startup is becoming a little bit annoying. These are the results of cProfile I got when running only one test: - 1.10.1: {{{ Using existing test database for alias 'default'... Preserving test database for alias 'default'... 29267726 function calls (28542239 primitive calls) in 41.733 seconds Ordered by: cumulative time ncalls tottime percall cumtime percall filename:lineno(function) 1422/1 0.024 0.000 41.737 41.737 {built-in method exec} 1 0.000 0.000 41.737 41.737 manage.py:2() 1 0.000 0.000 41.528 41.528 __init__.py:362(execute_from_command_line) 1 0.000 0.000 41.528 41.528 __init__.py:286(execute) 1 0.000 0.000 40.005 40.005 test.py:18(run_from_argv) 1 0.000 0.000 40.005 40.005 base.py:277(run_from_argv) 3/1 0.001 0.000 39.997 39.997 base.py:308(execute) 1 0.000 0.000 39.997 39.997 test.py:61(handle) 1 0.000 0.000 39.997 39.997 runner.py:535(run_tests) 1 0.000 0.000 39.655 39.655 runner.py:496(setup_databases) 1 0.000 0.000 39.655 39.655 runner.py:722(setup_databases) 1 0.000 0.000 39.655 39.655 creation.py:31(create_test_db) 2 0.000 0.000 33.294 16.647 __init__.py:79(call_command) 1 0.000 0.000 33.272 33.272 migrate.py:65(handle) 1 0.001 0.001 32.714 32.714 executor.py:66(_create_project_state) 205 0.002 0.000 32.638 0.159 migration.py:81(mutate_state) 473 0.036 0.000 32.441 0.069 state.py:103(reload_model) 351 0.058 0.000 30.502 0.087 state.py:263(render_multiple) 14865 0.690 0.000 30.195 0.002 state.py:528(render) }}} - 1.10: {{{ Using existing test database for alias 'default'... Preserving test database for alias 'default'... 8427740 function calls (7801541 primitive calls) in 9.000 seconds Ordered by: cumulative time ncalls tottime percall cumtime percall filename:lineno(function) 1420/1 0.028 0.000 9.005 9.005 {built-in method exec} 1 0.000 0.000 9.005 9.005 manage.py:2() 1 0.000 0.000 8.752 8.752 __init__.py:362(execute_from_command_line) 1 0.000 0.000 8.752 8.752 __init__.py:286(execute) 1 0.000 0.000 7.013 7.013 test.py:18(run_from_argv) 1 0.000 0.000 7.013 7.013 base.py:288(run_from_argv) 3/1 0.000 0.000 7.005 7.005 base.py:319(execute) 1 0.000 0.000 7.005 7.005 test.py:61(handle) 1 0.000 0.000 7.005 7.005 runner.py:535(run_tests) 1 0.000 0.000 6.634 6.634 runner.py:496(setup_databases) 1 0.000 0.000 6.634 6.634 runner.py:722(setup_databases) 1 0.000 0.000 6.634 6.634 creation.py:31(create_test_db) 1 0.000 0.000 6.403 6.403 creation.py:94(serialize_db_to_string) 1 0.000 0.000 6.374 6.374 __init__.py:123(serialize) 1 0.227 0.227 6.371 6.371 base.py:63(serialize) 18925 0.203 0.000 4.176 0.000 json.py:52(end_object) 18925 0.392 0.000 3.049 0.000 __init__.py:119(dump) }}} I am not including the whole result, but I could do so if needed. It seems to be related to changes in the 'executor.py' file. I looked for when this was changed and found this commit: https://github.com/django/django/commit/d5c4ea524679a787fe11c927448e44e95646096b I am not sure if this was an intended behavior so that's why I am filing this as an optimization instead of a bug." Cleanup/optimization closed Migrations 1.10 Normal fixed Simon Charette marten.knbk@… Ready for checkin 1 0 0 0 0 0