Django (?) really slow with large datasets after doing some python profiling

Question

Hi,

I was comparing an old PHP script of mine versus the newer, fancier Django version and the PHP one, with full spitting out of HTML and all was functioning faster. MUCH faster to the point that something has to be wrong on the Django one.

First, some context: I have a page that spits out reports of sales data. The data can be filtered by a number of things but is mostly filtered by date. This makes it a bit hard to cache it as the possibilities for results is nearly endless. There are a lot of numbers and calculations done but it was never much of a problem to handle within PHP.

UPDATES:

• After some additional testing there is nothing within my view that is causing the slowdown. If I am simply number-crunching the data and spitting out 5 rows of rendered HTML, it's not that slow (still slower than PHP), but if I am rendering a lot of data, it's VERY slow.

• Whenever I ran a large report (e.g. all sales for the year), the CPU usage of the machine goes to 100%. Don't know if this means much. I am using mod_python and Apache. Perhaps switching to WSGI may help?

• My template tags that show the subtotals/totals process anywhere from 0.1 seconds to 1 second for really large sets. I call them about 6 times within the report so they don't seem like the biggest issue.

Now, I ran a Python profiler and came back with these results:

Ordered by: internal time
   List reduced from 3074 to 20 due to restriction 

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
  2939417   26.290    0.000   44.857    0.000 /usr/lib/python2.5/tokenize.py:212(generate_tokens)
  2822655   17.049    0.000   17.049    0.000 {built-in method match}
  1689928   15.418    0.000   23.297    0.000 /usr/lib/python2.5/decimal.py:515(__new__)
 12289605   11.464    0.000   11.464    0.000 {isinstance}
   882618    9.614    0.000   25.518    0.000 /usr/lib/python2.5/decimal.py:1447(_fix)
    17393    8.742    0.001   60.798    0.003 /usr/lib/python2.5/tokenize.py:158(tokenize_loop)
       11    7.886    0.717    7.886    0.717 {method 'accept' of '_socket.socket' objects}
   365577    7.854    0.000   30.233    0.000 /usr/lib/python2.5/decimal.py:954(__add__)
  2922024    7.199    0.000    7.199    0.000 /usr/lib/python2.5/inspect.py:571(tokeneater)
   438750    5.868    0.000   31.033    0.000 /usr/lib/python2.5/decimal.py:1064(__mul__)
    60799    5.666    0.000    9.377    0.000 /usr/lib/python2.5/site-packages/django/db/models/base.py:241(__init__)
    17393    4.734    0.000    4.734    0.000 {method 'query' of '_mysql.connection' objects}
  1124348    4.631    0.000    8.469    0.000 /usr/lib/python2.5/site-packages/django/utils/encoding.py:44(force_unicode)
   219076    4.139    0.000  156.618    0.001 /usr/lib/python2.5/site-packages/django/template/__init__.py:700(_resolve_lookup)
  1074478    3.690    0.000   11.096    0.000 /usr/lib/python2.5/decimal.py:5065(_convert_other)
  2973281    3.424    0.000    3.424    0.000 /usr/lib/python2.5/decimal.py:718(__nonzero__)
   759014    2.962    0.000    3.371    0.000 /usr/lib/python2.5/decimal.py:4675(__init__)
   381756    2.806    0.000  128.447    0.000 /usr/lib/python2.5/site-packages/django/db/models/fields/related.py:231(__get__)
   842130    2.764    0.000    3.557    0.000 /usr/lib/python2.5/decimal.py:3339(_dec_from_triple)

tokenize.py comes out on top, which can make some sense as I am doing a lot of number formatting. Decimal.py makes sense since the report is essentially 90% numbers. I have no clue what the built-in method match is as I am not doing any Regex or similar in my own code (Something Django is doing?) The closest thing is I am using itertools ifilter.

It seems those are the main culprits and if I could figure out how to reduce the processing time of those then I would have a much much faster page.

Does anyone have any suggestions on how I could start on reducing this? I don't really know how I would fix this the tokenize/decimal issues without simply removing them.

Update: I ran some tests with/without filters on most of the data and the result times pretty much came back the same, the latter being a bit faster but not much to be the cause of the issue. What is exactly going on in tokenize.py?

Answer 1

There is a lot of things to assume about your problem as you don't have any type of code sample.

Here are my assumptions: You are using Django's built-in ORM tools and models (i.e. sales-data = modelobj.objects().all() ) and on the PHP side you are dealing with direct SQL queries and working with a query_set.

Django is doing a lot of type converting and casting to datatypes going from a database query into the ORM/Model object and the associated manager (objects() by default).

In PHP you are controlling the conversions and know exactly how to cast from one data type to another, you are saving some execution time based on that issue alone.

I would recommend trying to move some of that fancy number work into the database, especially if you are doing record-set based processing - databases eat that kind of processing from breakfast. In Django you can send RAW SQL over to the database: http://docs.djangoproject.com/en/dev/topics/db/sql/#topics-db-sql

I hope this at least can get you pointed in the right direction...

Answer 2

"tokenize.py comes out on top, which can make some sense as I am doing a lot of number formatting. "

Makes no sense at all.

See http://docs.python.org/library/tokenize.html.

The tokenize module provides a lexical scanner for Python source code, implemented in Python

Tokenize coming out on top means that you have dynamic code parsing going on.

AFAIK (doing a search on the Django repository) Django does not use tokenize. So that leaves your program doing some kind of dynamic code instantiation. Or, you're only profiling the first time your program is loaded, parsed and run, leading to false assumptions about where the time is going.

You should not ever do calculation in template tags -- it's slow. It involves a complex meta-evaluation of the template tag. You should do all calculations in the view in simple, low-overhead Python. Use the templates for presentation only.

Also, if you're constantly doing queries, filters, sums, and what-not, you have a data warehouse. Get a book on data warehouse design, and follow the data warehouse design patterns.

You must have a central fact table, surrounded by dimension tables. This is very, very efficient.

Sums, group bys, etc., are can be done as defaultdict operations in Python. Bulk fetch all the rows, building the dictionary with the desired results. If this is too slow, then you have to use data warehousing techniques of saving persistent sums and groups separate from your fine-grained facts. Often this involves stepping outside the Django ORM and using RDBMS features like views or tables of derived data.

Answer 3

When dealing with large sets of data, you can also save a lot of CPU and memory by using the ValuesQuerySet that accesses the query results more directly instead of creating a model object instance for each row in the result.

It's usage looks a bit like this:

Blog.objects.order_by('id').values()

Answer 4

In such a scenario the database is often the bottleneck. Also, using an ORM might result in sub-optimal SQL queries.

As some pointed out it's not possible to tell what the probem really is, just with the information you provided.

I just can give you some general advice:

• If your view is working with related model objects, consider using select_related(). This simple method might speed up the queries generated by the ORM considerably.
• Use the Debug Footer Middleware to see what SQL queries are generated by your views and what time they took to execute.

PS: Just fyi, I had once a fairly simple view which was very slow. After installing the Debug Footer Middleware I saw that around 500! sql queries were executed in that single view. Just using select_related() brought that down to 5 queries and the view performed as expected.