Very Slow Django: Multiple SHOW Default_transaction_isolation Calls in the Log

Question

I am using Django 1.5.4 with PostgreSQL 9.2.4.-2 through psycopg2 2.5.1.

From some point in time, I noticed that my Django site became very slow - it takes only 2-3 seconds to load small pages with a few easy queries.

The Django-debug toolbar says:

241,70 ms (161 queries) - query time

time 2992ms - total page load time

So, queries should not be a problem ... But it is not! I installed postgresql query logging and I got the following:

 [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 

After my target request, there is a SHOW default_transaction_isolation request. The magazine says that it takes 0.086 ms to complete this strange request, but it creates around 10 ms of delay around it:

• request number 1 completed 11:17: 05.148
• strange request
• request number 2 completed 11:17: 05.158

Does anyone know if this is a bug of django, psycopg, postgres or any other application? How can I research this?

UPD The Pure Django project (only Django, postgresql, psycopg2) executes queries without this error. Perhaps there is something in the project applications or third-party applications. I'm trying to investigate.

Answer 1

It took me a few days to discover the source of the problem. It took me a long time because of my wrong guesses: I was sure that the problem was caused somehow by the database or database connection library. Python

The reason was django-debug-toolbar - as I understand it, measuring SQL runtime results in poor overall performance.

As a result, if your Django site is slow, check if DEBUG = False and django-debug-toolbar disabled.