Slow test startup under Django 1.7

[Warren Smith]

I'm in the process of converting a large legacy app from Django 1.5 to 1.7. I've got all the tests passing, so I'm researching an issue I noticed during the course of my work: Test startup takes MUCH longer under Django 1.7 than it did under 1.5. I've got a test that, when run by itself, took a total of 5 seconds under 1.5. Under 1.7 it takes over a minute.

To isolate the test startup, I setup a do-nothing test method within a subclass of django.test.TestCase. I ran it under Django 1.5 and 1.7 with similar results to the existing "real" test.

I ran the do-nothing test within cProfile under Django 1.7 and found something very interesting. According to pstats, the method django.apps.config.AppConfig.get_models() was called 2.2+ MILLION times. Even with 79 django apps in my INSTALLED_APPS setting, that seems excessive.

I read the Django 1.7 release notes, especially the App Config stuff. I noticed the warning about not importing models in the application root module. I went through all of our internal apps and made sure they were not importing models in the root module. I had to make some changes, moving imports inside functions/methods. I also looked at my third-party dependency apps. None of those were importing their models in their root modules.

After all that, though, I still see no change in behavior.

I thought I might have some loop happening somewhere, though why it wasn't infinite was interesting. It would be nice to know more about the context of those get_models() calls. Perhaps I had a couple of mis-behaving apps locked in a deadly embrace of some sort.

I hacked on my locally installed django.apps.config.AppConfig class, adding a class-level collections.Counter that gets incremented for self.label by the get_models() method.

I dumped the results to a json file within my do-nothing test. It wouldn't be comprehensive, but at least it would show me what had happened before the test ran.

I expected to see a few big numbers and a lot of small ones. As often happens when profiling, my expectations were completely wrong. All the counts were very similar, all in the 6000-7999 range. All 79 of my apps were represented.

Is there some sort of cartesian product going on here?

Is this behavior normal and expected?

[Markus Holtermann]

Hey Warren,

this is a known problem in 1.7. It is fixed in 1.8 (see https://code.djangoproject.com/ticket/23745). Unfortunately, the changes made to reduce the amount of get_models() and render() calls are too invasive to backport them to 1.7.

If you have the time, could you try running your project on the 1.8 alpha version and check the changes out and provide some feedback on how that turned out?

Thanks in advance.

/Markus