Как отловить замедление ответа nginx+uwsgi+django?

Question

[kazmiruk]

Здравствуйте

Проблема следующая. Есть 2 релиза. 1ый релиз укладывает время ответа для 90% запросов в 60мс. Выкатка второго релиза (более нового) увеличивает это время до 250мс. Первым же делом просмотрел все коммиты, которые составляют второй релиз. Ничего криминального не нашел (примерно 95% стили и верстка). Пытался выкатывать различные релизы с отключением части изменений, ничего тоже не нашлось (но тут есть проблема, так как на продакшене это делать не круто, да и начинает проявляться не сразу, поэтому попытался в таком режиме с самыми подозрительными коммитами). Пытался воспроизвести локально - никаких отличий по времени ответа не увидел. PgBounser говорит, что время ответа от базы не менялось, т.е. ее можно исключить. Закончились мысли. Собственно вопрос состоит в следующем:
- куда копать, что смотреть на продакшене?
- замедление времени ответа начинает проявляться не сразу, а примерно через 30 минут, хотя после выкладки релиза делается reload всех процессов. С чем это может быть связано?
На графиках еще при выкладке релиза видно небольшое изменение количества запросов, что путает еще больше. 1 релиз - быстрый ответ, много запросов, 2 релиз - медленный ответ, мало запросов.
Окружение такое: django 1.6, django-jinja + jinja2, postgres + pgbouncer, redis под сессии и кеш, все это дело за nginx.

Comments

[un1t]

Размер базы на тестинге и проде одинаковый?

[kazmiruk]

un1t: нет, размеры не одинаковые. Но время ответа от базы от релиза к релизу не меняется.

[un1t]

kazmiruk: попробуй попрофилировать запросы, или скажем логировать медленные. Возможно где-то промахнулись мимо индекса, а на тесте не отлавливается, раз база меньше.

Answer 1

[kazmiruk]

Все оказалось очень интересным. Время смтотрелось как среднее время ответа. После релиза ушёл асинхронный запрос, который отрабатывались очень быстро и часто. Соответственно этот запрос перестал маскировать реальные проблемы на сервере с временем ответа в 350 мс.

Answer 2

[He11ion]

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

Comments

[kazmiruk]

Хм, как бы это не звучало тупо, но я почему-то не подумал даже про этот самый очевидный вариант. Надо глянуть по памяти, вполне возможно, что что-то начало течь.

Answer 3

[sim3x]

Настроить nginx для лога response time
возможно получишь вью
stackoverflow.com/questions/14592773/nginx-request...

log_format  main  '$remote_addr|$time_local]|$request|$request_time|$upstream_response_time|'
                  '$status|$body_bytes_sent|$http_referer|'
                  '$http_user_agent';

uwsgi-docs.readthedocs.org/en/latest/Changelog-1.9...
lists.unbit.it/pipermail/uwsgi/2012-July/004474.html
projects.unbit.it/uwsgi/wiki/TipsAndTricks

I include the --profiler option too

--profiler pycall

--profiler pyline

they will write function timings in the logs. You can analize logs to find
bottleneck (not an easy task, but it should be doable investing a bit of
time in log parser)