Почему бот Яндекс Маркета не успевает получить ответ от nginx за 150 секунд, даже код 304 Not Modified?

Question

[heinlein]

Раз в, примерно, 20 минут на сайт заходит бот Яндекса чтобы скачать свежие прайс-листы или убедиться в том, что они не изменились. Как правило операция завершается успешно, но раз в сутки (время меняется, чаще по ночам) ему не удается получить ответ от сервера за отведенные 150 секунд и он отключается с ошибкой 408 Request Timeout. Причем как правило такие неудачные попытки случаются по две подряд.

В логах nginx при этом в соответствующее ошибкам в админке Маркета время ответ формируется нормально, занимает максимум 30 секунд если архив с прайс-листами не закэширован (пробовал отключить кэширование для директории с прайсами, не помогло), в случае если код ответа 304 -- сервер отвечает моментально.

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

Нагрузка на сервер в те моменты, когда это происходит, обычная (согласно ISPManager), и в целом в течение дня достаточно низкая, перебоев в работе самого сайта тоже нет.

Как это можно дебажить, куда копать?

Настройки nginx, которые могут быть релевантны:

proxy_read_timeout 1600;
proxy_send_timeout 1600;
proxy_connect_timeout 1600;
keepalive_timeout  150;
client_body_timeout 150;
client_header_timeout 150;

Также пробовал следующее, не помогло:

send_timeout 1600;
fastcgi_read_timeout 1600;
proxy_max_temp_file_size 2048m;
proxy_buffers 16 16k;
proxy_buffer_size 16k;

Answer 1

[Алексей Сундуков]

А этот файл формирует бекенд? То, что это происходит ночью наталкивает на мысль бэкапах либо других видах сервисных работ. У вас VDS/VPS?
Предлагают добавить такой формат лога в основной конфиг:

log_format  with_time '$remote_addr - $remote_user [$time_local] "$request" '
                      '$status $body_bytes_sent "$http_referer" '
                      '"$http_user_agent" "$http_x_forwarded_for" rqt=$request_time urst=$upstream_response_time';

В конфиге сервера задается:

access_log  /путь_до_файла_лога/access.log with_time;

Это позволит видеть время забора клиентом ответа (большое значение - проблема с клиентом/сетью до клиента) и время ответа бэка (большое значение - проблемы на беке). В зависимости от результатов нужно дальше думать куда двигаться.

Comments

[heinlein]

Спасибо за подробный ответ.

Это не всегда происходит ночью, сравнивал со временем бэкапов и ресурсоемких фоновых заданий на сервере -- редко совпадает.

Да, VPS. Время всего запроса и работы бэкенда логгируется, бэкенд в этом не участвует (файлы статические), так что там прочерк, запрос происходит в среднем быстрее чем за секунду (максимальное значение 40 секунд), но видимо присутствует задержка ощутимая задержка до того, как nginx начнет реагировать на запрос.

Выставил worker_processes 4 по числу ядер, вроде как за сутки ошибка не появлялась, но пока рано радоваться.

Еще запросил подробные логи у ТП Яндекс Маркета, возможно ситуация прояснится.

[Алексей Сундуков]

heinlein, VPS означает разделение ресурсов с соседями. В зависимости от используемой схемы могут быть нюасы при которых соседи будут забирать ресурсы. С учетом того, что "происходит в разное время", то вероятна именно эта ситуация. worker_processes возможно не будет иметь эффекта, т.к. в хост машине скорее всего выделяется просто время на ЦПУ.
На сколько большой файл? Для исключения проблем чтения с диска и при небольшом размере файла есть смысл сложить его в ОЗУ. Либо через ramdisk (Хранение кэша в оперативной памяти) либо хранением в том же Redis. Если и после этого проблемы будут происходить, то значит проблема именно в сети, но повлиять на это в рамках этого VPS вероятно не получится. Но если это сеть, то стоит тогда попробывать связаться с хостером с вопросом каким образом виртуальке выделяется сеть и какую полосу они могут гарантировать в какой промежуток времени. Т.е по сути уточнить, каким образом происходит распределение ресурсов между виртуальными серверами.

Answer 2

[Dimonchik]

копать в сеть

Comments

[heinlein]

Можете немного развернуть?

[Dimonchik]

если сервер не в напряге, очевидно проблема с соединением

Answer 3

[Vitaly Karasik]

Как это можно дебажить, куда копать?

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

- а какое время ответа в остальные часы?
- я бы просимулировал запрос самостоятельно, и понаблюдал в это время за nginx и базой данных

Comments

[heinlein]

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

Судя по логам nginx в среднем сам ответ занимает меньше секунды, максимальное значение, которое встречалось это 40 секунд, но ошибок в это время не было. Зато были когда возвращался 304 и nginx времени на ответ грубо говоря вообще не тратил. БД в процессе не участвует, файлы статические и автоматически обновляются раз в сутки. Со временем обновления ошибки бота не совпадают.

Потыкал уже курлом в файл с другого сервера -- отвечает штатно, соединение и получение файла занимают пару секунд, в логах тоже все ожидаемо.

А за чем кроме логов можно у nginx понаблюдать?

[Vitaly Karasik]

Потыкал уже курлом в файл с другого сервера -- отвечает штатно, соединение и получение файла занимают пару секунд, в логах тоже все ожидаемо.

максимальное значение, которое встречалось это 40 секунд, но ошибок в это время не было. Зато были когда возвращался 304 и nginx времени на ответ грубо говоря вообще не тратил.

Советую запустить cron  для проверки в течении суток и посмотреть есть ли какие-то задержки.

[heinlein]

Ясно, спасибо за совет.