非常慢的Django:在日志中调用多个"SHOW default_transaction_isolation"

Question

我正在使用Django 1.5.4和PostgreSQL 9.2.4.-2到psycopg2 2.5.1.

从某些时候起,我注意到我的Django网站变得非常慢 - 只需要2-3秒就可以加载只有几个轻量级查询的小页面.

Django-debug-toolbar说:

241,70 ms (161 queries) - 查询时间

time 2992ms - 总页面加载时间

所以,查询不应该是问题......但事实并非如此!我已经设置了postgresql查询日志记录,我得到了这个:

[LOG ENTRY] 2013-09-18 11:17:05.148 MSK 10304 127.0.0.1(38834)LOG:  duration: 0.762 ms  statement: SELECT ...
[LOG ENTRY] 2013-09-18 11:17:05.155 MSK 10304 127.0.0.1(38834)LOG:  duration: 0.086 ms  statement: SHOW default_transaction_isolation
[LOG ENTRY] 2013-09-18 11:17:05.158 MSK 10304 127.0.0.1(38834)LOG:  duration: 0.804 ms  statement: SELECT ...
[LOG ENTRY] 2013-09-18 11:17:05.164 MSK 10304 127.0.0.1(38834)LOG:  duration: 0.092 ms  statement: SHOW default_transaction_isolation
[LOG ENTRY] 2013-09-18 11:17:05.168 MSK 10304 127.0.0.1(38834)LOG:  duration: 0.757 ms  statement: SELECT ...
[LOG ENTRY] 2013-09-18 11:17:05.175 MSK 10304 127.0.0.1(38834)LOG:  duration: 0.085 ms  statement: SHOW default_transaction_isolation
[LOG ENTRY] 2013-09-18 11:17:05.178 MSK 10304 127.0.0.1(38834)LOG:  duration: 0.779 ms  statement: SELECT ...
[LOG ENTRY] 2013-09-18 11:17:05.185 MSK 10304 127.0.0.1(38834)LOG:  duration: 0.091 ms  statement: SHOW default_transaction_isolation
[LOG ENTRY] 2013-09-18 11:17:05.190 MSK 10304 127.0.0.1(38834)LOG:  duration: 1.492 ms  statement: SELECT ...
[LOG ENTRY] 2013-09-18 11:17:05.197 MSK 10304 127.0.0.1(38834)LOG:  duration: 0.090 ms  statement: SHOW default_transaction_isolation

SHOW default_transaction_isolation我的目标查询后有一个查询.Log表示执行这个奇怪的查询需要0.086毫秒,但它会在它周围产生大约10毫秒的延迟:

• 查询#1完成了11:17:05.148
• 奇怪的查询
• 查询#2完成了11:17:05.158

有谁知道这是django,psycopg,postgres或任何其他应用程序的错误？我怎么调查这个？

UPD纯Django项目(只有Django,postgresql,psycopg2)执行没有该bug的查询.也许项目的应用程序或第三方应用程序中有一些东西.我正在努力调查.

Answer 1

我花了几天时间才发现问题的根源.由于我的错误猜测花了这么多时间:我确信问题是由数据库或数据库-python连接库以某种方式引起的.

原因是django-debug-toolbar - 据我所知,它对SQL执行时间的测量通常会导致性能不佳.

作为总结,如果你的Django网站速度很慢-检查是否DEBUG = False和django-debug-toolbar关闭.