#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 [email protected].
To post to this group, send email to [email protected].
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