Запросы Django в 40 раз медленнее, чем идентичные запросы Postgres?

Question

Я бегу Django 1.7 с Postgres 9.3, работает с runserver. Моя база данных содержит около 200 м строк или около 80 ГБ данных. Я пытаюсь отлаживать, почему одни и те же запросы достаточно быстро работают в Postgres, но медленны в Django.

Структура данных, как это:

class Chemical(models.Model): 
    code = models.CharField(max_length=9, primary_key=True) 
    name = models.CharField(max_length=200) 

class Prescription(models.Models): 
    chemical = models.ForeignKey(Chemical) 
    ... other fields 

База данных создана с C обобщению и соответствующими индексами:

        Table "public.frontend_prescription" 
    Column  |   Type   |        Modifiers 
id    | integer     | not null default nextval('frontend_prescription_id_seq'::regclass) 
chemical_id  | character varying(9) | not null 
Indexes: 
    "frontend_prescription_pkey" PRIMARY KEY, btree (id) 
    "frontend_prescription_a69d813a" btree (chemical_id) 
    "frontend_prescription_chemical_id_4619f68f65c49a8_like" btree (chemical_id varchar_pattern_ops) 

Это мое мнение:

def chemical(request, bnf_code): 
    c = get_object_or_404(Chemical, bnf_code=bnf_code) 
    num_prescriptions = Prescription.objects.filter(chemical=c).count() 
    context = { 
     'num_prescriptions': num_prescriptions 
    } 
    return render(request, 'chemical.html', context) 

Узким местом является .count(). вызов. Панель инструментов Django отладки показывает, что время, потраченное на это 2647ms (под «Время» заголовок ниже), но EXPLAIN раздел предполагает время, потраченное должно быть 621ms (в нижней части):

Даже незнакомец, если я запускаю тот же запрос непосредственно в Postgres, кажется, принимает только 200-300ms:

# explain analyze select count(*) from frontend_prescription where chemical_id='0212000AA'; 

QUERY PLAN 
------------------------------------------------------------------------------------------------------------------------------------------------------------- 
Aggregate (cost=279495.79..279495.80 rows=1 width=0) (actual time=296.318..296.318 rows=1 loops=1) 
    -> Bitmap Heap Scan on frontend_prescription (cost=2104.44..279295.83 rows=79983 width=0) (actual time=162.872..276.439 rows=302389 loops=1) 
     Recheck Cond: ((chemical_id)::text = '0212000AA'::text) 
     -> Bitmap Index Scan on frontend_prescription_a69d813a (cost=0.00..2084.44 rows=79983 width=0) (actual time=126.235..126.235 rows=322252 loops=1) 
       Index Cond: ((chemical_id)::text = '0212000AA'::text) 
Total runtime: 296.591 ms 

Так что мой вопрос: в панели инструментов отладки, то EXPLAIN заявление отличается от фактической производительности в Django. И это медленнее, чем исходный запрос в Postgres.

Почему существует это несоответствие? И как мне отладить это/улучшить производительность моего приложения Django?

ОБНОВЛЕНИЕ: Вот еще один случайный пример: 350 мс для EXPLAIN, более 10 000 для рендеринга! Помогите, это делает мое приложение Django практически непригодным для использования.

UPDATE 2: Вот панель Профилирование еще медленных (40 секунд в Django, 600мс в EXPLAIN ...) запрос. Если я правильно ее читаю, это говорит о том, что каждый вызов SQL из моего представления занимает 13 секунд ... это узкое место?

Что странно, что профилированные звонки медленно только для запросов, которые возвращают много результатов, так что я не думаю, что задержка некоторые Джанго соединения накладных расходов, которая применяется к каждому вызову.

ОБНОВЛЕНИЕ 3: Я пробовал переписывать представление в необработанном SQL, и производительность теперь улучшается некоторое время, хотя я все еще вижу медленные запросы примерно в половине случаев. (Мне нужно создавать и повторно создавать курсор каждый раз, иначе я получаю InterfaceError и сообщение о мертвом курсоре - не уверен, что это полезно для отладки. Я установил CONN_MAX_AGE=1200.) В любом случае, это выполняется нормально, хотя, очевидно, он уязвим для инъекций и т.д., как написано:

cursor = connection.cursor() 
query = "SELECT * from frontend_chemical WHERE code='%s'" % code 
c = cursor.execute(query) 
c = cursor.fetchone() 
cursor.close() 

cursor = connection.cursor() 
query = "SELECT count(*) FROM frontend_prescription WHERE chemical_id=" 
query += "'" + code + "';" 
cursor.execute(query) 
num_prescriptions = cursor.fetchone()[0] 
cursor.close() 

context = { 
    'chemical': c, 
    'num_prescriptions': num_prescriptions 
} 
return render(request, 'chemical.html', context) 

Answer 1

весьма вероятно, что, когда Джанго выполняет запрос, данные должны быть считаны с диска. Но когда вы проверяете, почему запрос был медленным, данные уже находятся в памяти из-за более раннего запроса.

Самые простые решения - это купить больше памяти или более быструю систему io.

Answer 2

Это не надежный код профилирования на вашей машине разработки (раскрывается в комментариях, всевозможные вещи работают на вашем рабочем столе, что может мешать). Это также не покажет вам реальную производительность для изучения времени выполнения с активной панелью django-debug-toolbar. Если вас интересует, как эта вещь будет действовать в дикой природе, вы должны запустить ее в своей предполагаемой инфраструктуре и измерить ее с легким прикосновением.

def some_view(request): 
    search = get_query_parameters(request) 
    before = datetime.datetime.now() 
    result = ComplexQuery.objects.filter(**search) 
    print "ComplexQuery took",datetime.datetime.now() - before 
    return render(request, "template.html", {'result':result}) 

Затем вам нужно запустить это несколько раз, чтобы разогреть кеши, прежде чем вы сможете делать какие-либо измерения. Результаты будут сильно зависеть от настроек. Вы могли бы использовать пул соединений, который требует разогрева, postgres быстрее при последующих запросах одного и того же типа, django также может быть настроен на наличие локального кеша, все из которых требуют раскрутки, прежде чем вы сможете точно сказать, что это , что запрос ,

Все инструменты профилирования сообщают о времени, не задумываясь о замедлении их самоанализа, вы должны относиться к относительному подходу и использовать DDT (или мой любимый для этих проблем: django-devserver) для определения горячих точек в обработчиках запросов, которые последовательно выполняют плохо , Еще один инструмент, заслуживающий внимания: linesman. Это немного хлопот, чтобы настраивать и поддерживать, но действительно очень полезно.

Я отвечал за довольно большие настройки (размер DB в десятках ГБ) и не видел простой запрос, похожий на этот прогон. Сначала выясните, действительно ли у вас проблема (что это не просто запуск сервера, разрушающий ваш день), а затем используйте инструменты, чтобы найти эту точку доступа, а затем оптимизировать.