#27279: Slow test framework initialization in 1.10.1 compared to 1.10
--------------------------------------+--------------------
     Reporter:  mtomiyoshi            |      Owner:  nobody
         Type:  Cleanup/optimization  |     Status:  new
    Component:  Testing framework     |    Version:  1.10
     Severity:  Normal                |   Keywords:
 Triage Stage:  Unreviewed            |  Has patch:  0
Easy pickings:  0                     |      UI/UX:  0
--------------------------------------+--------------------
 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(<module>)
         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(<module>)
         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.

--
Ticket URL: <https://code.djangoproject.com/ticket/27279>
Django <https://code.djangoproject.com/>
The Web framework for perfectionists with deadlines.

-- 
You received this message because you are subscribed to the Google Groups 
"Django updates" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to django-updates+unsubscr...@googlegroups.com.
To post to this group, send email to django-updates@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/django-updates/053.24a486630d33ca64a1b7c061932e4467%40djangoproject.com.
For more options, visit https://groups.google.com/d/optout.

Reply via email to