Django 查询比相同的 Postgres 查询慢 40 倍？

Question

我正在运行 Django 1.7 和 Postgres 9.3，使用 runserver 运行。我的数据库中有大约 2 亿行或大约 80GB 的数据。我正在尝试调试为什么相同的查询在 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 调试工具栏显示花费的时间是 2647 毫秒(在下面的“时间”标题下)，但是 EXPLAIN 部分建议花费的时间应该是 621 毫秒(在底部):

更奇怪的是，如果我直接在 Postgres 中运行相同的查询，它似乎只需要 200-300 毫秒:

# 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 应用程序的性能？

更新:这是另一个随机示例:EXPLAIN 需要 350 毫秒，渲染时间超过 10,000 毫秒!帮助，这让我的 Django 应用程序几乎无法使用。

更新 2:这是另一个慢查询(在 Django 中为 40 秒，在 EXPLAIN 中为 600 毫秒...)查询的分析面板。如果我没看错，它表明从我的角度来看每个 SQL 调用都需要 13 秒...这是瓶颈吗？

奇怪的是，分析调用只对返回大量结果的查询很慢，所以我不认为延迟是适用于每个调用的一些 Django 连接开销。

更新 3: 我尝试用原始 SQL 重写 View ，现在有时性能更好，尽管我仍然有大约一半的时间查询缓慢。 (我每次都必须创建和重新创建光标，否则我会收到 InterfaceError 和一条关于光标已死的消息 - 不确定这是否对调试有用。我已经设置了 CONN_MAX_AGE=1200。)无论如何，这执行正常，但显然它容易受到注入(inject)等攻击，如所写:

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

在您的开发机器上它不是可靠的分析代码(在评论中显示，您的桌面上运行的各种东西可能会干扰)。它也不会向您展示真实世界的性能来检查运行时 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 也可能设置有一些本地缓存，所有这些都需要启动才能确定它是 查询。

所有分析工具报告时间时都没有考虑到它们自身的自省(introspection)速度减慢，您必须采取相对的方法并使用 DDT(或我最喜欢的这些问题:django-devserver)来识别请求处理程序中始终执行的热点很糟糕。另一个值得注意的工具:linesman .设置和维护起来有点麻烦，但确实非常有用。

我一直负责相当大的设置(数据库大小为数十 GB)并且还没有看到像这样严重搁浅的简单查询。首先找出您是否真的有问题(不仅仅是 runserver 毁了您的一天)，然后使用工具找到该热点，然后进行优化。