Databases
StackOverflow2013
Postsdbo
POVery slow Django: Multiple "SHOW default_transaction_isolation" calls in log
Body
 

Note that there are some explanatory texts on larger screens.

plurals
  1. POVery slow Django: Multiple "SHOW default_transaction_isolation" calls in log
    text
    copied!<p>I am using Django 1.5.4 with PostgreSQL 9.2.4.-2 through psycopg2 2.5.1.</p> <p>From some point of time I noticed that my Django site became extremely slow - it takes about 2-3 seconds to load small pages with only several lightweight queries.</p> <p>Django-debug-toolbar says:</p> <p><code>241,70 ms (161 queries)</code> - query time</p> <p><code>time 2992ms</code> - total page load time</p> <p>So, the queries should not be the problem... But that's not true! I've set up postgresql query logging and I got this:</p> <pre><code>[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 </code></pre> <p>There is a <code>SHOW default_transaction_isolation</code> query after my target query. Log says that it takes 0.086 ms to perform this strange query, but it creates about 10 ms delays around it:</p> <ul> <li>query #1 finished 11:17:05.148</li> <li>strange query</li> <li>query #2 finished 11:17:05.158</li> </ul> <p>Does anybody know whether this is a bug of django, psycopg, postgres or any other app? How can I investigate this?</p> <p><strong>UPD</strong> Pure Django project (only Django, postgresql, psycopg2) executes queries without that bug. Maybe there is something in project's apps or third-party apps. I'm trying to investigate.</p>
 

Querying!

 
Guidance
An individual column

Larger individual text columns get their own page to allow for proper reading.

SQuiL has stopped working due to an internal error.

If you are curious you may find further information in the browser console, which is accessible through the devtools (F12).

Reload