Назад | Перейти на главную страницу

Как отлаживать медленные запросы в Django + Postgres

Мои запросы к базе данных из Django начинают занимать 1-2 секунды, и мне трудно понять, почему. Не слишком большой сайт, около 1-2 запросов в секунду (которые попадают в Django; статические файлы просто обслуживаются из nginx.)

Меня смущает то, что я могу воспроизвести медлительность в оболочке Django, используя режим отладки. Но когда я отправляю точно такие же запросы в командной строке sql, они работают быстро. Для возврата запроса требуется около секунды, но когда я проверяю connection.queries, он сообщает время, как менее 10 мс.

Вот пример (из оболочки Django):

>>> p = PlayerData.objects.get(uid="100000521952372")
>>> a = time.time(); p.save(); print time.time() - a
1.96812295914
>>> for d in connection.queries: print d["time"]
... 
0.002
0.000
0.000

Как я могу выяснить, на что тратится это дополнительное время?

Я использую Apache + mod_wsgi в режиме демона, но это также происходит только с оболочкой django, поэтому я полагаю, что это не связано с apache.

У меня была эта проблема, кроме MySQL. Была страница администратора, которая загружалась очень долго (15 секунд), но самый медленный запрос длился всего несколько секунд. Спустя несколько часов отладки я узнал, что это было.

Сервер базы данных mysql действительно возвращал результаты запроса всего за несколько секунд, но обработка запроса не была полностью завершена (до конца срока службы, включая очистку), пока после результаты вернулись. Вот пошаговое объяснение того, что происходило:

Дорогой запрос попадает в базу данных
Сервер MySQL возвращает результаты запроса через несколько секунд, но продолжает работать над очисткой (запрос еще не достиг конца срока службы, что касается сервера mysql). Время, затраченное на этот запрос, как показано на панели инструментов отладки django (и django.db.connection.queries), перестает отсчитываться после возврата результатов.
Django возвращает результаты и продолжает загружать страницу, в то же время на заднем фоне, mysql продолжает очищать используемую временную таблицу.
Django готовит еще один запрос sql и отправляет его на сервер.
MySQL еще не завершил очистку временной таблицы, поэтому ...
Джанго должен сидеть и ждать. Django использует то же соединение mysql db, что и раньше, и mysql не позволит тому же соединению запустить другой запрос, пока предыдущий не достигнет конца срока службы, включая очистку.

Я понял это, запустив «показать полный список процессов»; в командной строке mysql. Для всех невыполненных запросов он показывает время, потраченное на запрос (на данный момент), статус и фактический текст запроса. Через три или 4 секунды после запуска дорогостоящего запроса он начнет показывать «удаление таблицы tmp» в качестве статуса. Он будет показывать это в течение 7 секунд после того, как запрос уже вернул результаты в Django. Таким образом, очевидно, что MySQL требовал гораздо больше времени для очистки запроса, чем для фактического возврата результатов. В этом и заключалась проблема в моем случае.

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

Не уверен, что это ваша проблема, но я полагаю, что это стоит изучить.

Отличным дополнением для Django является панель инструментов отладки Django (github.com/robhudson/django-debug-toolbar). Он покажет вам запросы, которые вы делаете при каждой загрузке страницы (вместе с выводом объяснения для каждого запроса).

Какую версию Django вы используете? Конюшня или багажник? 1.x? 0,9x? Только одну вещь вы можете проверить. Что вы имеете в виду под «точными запросами». Вы используете пользовательские SQL-запросы с Django или получили запрос и запустили его в оболочке SQL.

Другая «дикая догадка»: находится ли база данных на том же компьютере? Возможно, у вас проблема с сетью с задержкой. Когда вы открываете запрос SQL, вы уже подключены к серверу базы данных, а Django должен установить соединение?

Как я уже говорил, это просто дикая догадка. Проблема с сетью, с которой я столкнулся сам, из-за всего брандмауэра / маршрутизации в нашей компании. Но не такая уж большая задержка.