17 секунд задержка на первый запрос к серверу?

Question

[dmitri_kotov_PhD]

Всем привет.

Дано: сайт на dedicated server, Centos 7.9 (ядро 6.3.9-1.el7.elrepo.x86_64) + nginx 1.27 + Wordpress (+ WPRocket, + Redis object cache).

Есть проблема: ~2-3 раза в день, возникает проблема: ПЕРВОЕ обращение к сайту зависает на 17 секунд.
Все последующие запросы отрабатывают очень быстро.

У кого-нибудь бывало такое?

Также:
В Google PageSpeed для desktop: 97 баллов.
Monit говорит, что всё прекрасно.

URL сайта дать не могу. Могу показать конфиги nginx.

Проверял второй имеющийся сервер (vps): там такой проблемы нет. Оба сервера в Дубае, в одном датацентре. Оба настраивал сам. Второй сервер "работает" на поддомене первого сервера, т.е. даже их домены описаны в одной доменной зоне в cloudflare.
Со вторым сервером всё прекрасно, а с этим нет.
Проверяю из России.

Что сделано:
проверена вся цепочка.. и доменная зона в cloudflare, и DNS в /etc/resolv.conf, и конфиги nginx, и тонкая настройка centos, redis, и все логи сервера.

Что я нахожу СТРАННЫМ: в chrome dev tools (Yandex Browser), таймлинии процесса загрузки в проблемном случае просто начинаются после 17-ти секундной задержки. См. скрин в прикреплении.


Нет никаких stalled state. Сам ответ сервера шустрый на всех стадиях. Как на графике, так и вживую, но за исключением 17-ти секундного лага при ПЕРВОМ запросе, и то лишь ИНОГДА.
Проверял с разных компьютеров.
Сам сайт получает по 2-3 запроса в секунду в среднем. Не простаивает.

Исходя из диаграммы, запрос сначала где-то ждёт 17 секунд, а потом молниеносно выполняется.
Перегруза сервера нет! Со стороны chrome dev tools Stalled state также в диаграмме отсутствует.
В сервере достаточно свободной ОЗУ и места на диске.
Судя по диаграмме, сигнал даже не доходит до сервера, а где-то тормозится. Но только первый запрос. Как так??
Думал на DNS, на SSL shake, нигде не нашёл проблем.

Кто-нибудь знает, в чём может быть засада?

Comments

[agpecam]

РКН

[dmitri_kotov_PhD]

Придётся копать strace, видимо.
Кто-нибудь знает, как правильно мониторить всё, что происходит на сервере при поступлении запроса к сайту?

Именно с strace опыта нет. Как-то не нужно было.
По-видимому, нужно мониторить nginx при помощи strace, прежде всего, и дальше по цепочке (PHP и т.д.)
Вопрос в том: а если проблема, например, где-то в неправильных настройках TCP? За это ведь ОС отвечает. Как это проверить.. не знаю.

К слову, TCP slow start отключен.

[dmitri_kotov_PhD]

Оказалось, тормозит в совсем неожиданном месте: при установке cookie для woocommerce.
Запрос поступает на сервер, дальше setcookie для woocommerce, дальше ~17 секунд система тупит. Затем выставляет куку.
Что там происходит, не представляю, т.к. отловить снова эту задержку пока не удалось.

[Sumato]

Аналогичная проблема (VPS, Ubuntu, ISPmanager, зона на Яндексе и другой движок), только "срабатывает" чаще... и тоже подозрение на куку .

[dmitri_kotov_PhD]

Провёл strace nginx и php-fpm.
У меня получилось, что в течение этих 17 секунд Wordpress грузит файлы php. Не нашёл явной проблемы именно в куке.
В моём случае, расход ОЗУ близок к лимитам. Как понимаю, сервер компилит/подгружает все файлы php для нового пользователя, но не для каждого. Памяти не хватает, видимо.

(3Гб свободно из 64Гб. 50+Гб занимает кэш, сайт под регулярной нагрузкой и имеет большой кэш)

[dmitri_kotov_PhD]

Как понимаю, никто толком не знает, в чём дело.

Answer 1

[ky0]

 Дамп трафика снимите (желательно на обеих сторонах, чтобы потом сравнить) - из него станет понятно, кто там кого ждёт.

Comments

[dmitri_kotov_PhD]

Попробую, спасибо. Думал в эту сторону, но это мне представляется практически нереальным: со стороны сервера запускать tcpdump в произвольный момент, отлавливая не очень часто воспроизводимый случай возникновения проблемы.
Надеялся, может есть способ более верный и быстрее.
Но спасибо большое, буду пробовать.

[dmitri_kotov_PhD]

Удалось поймать момент, когда проблема есть.
Дамп трафика:
Вот эти строки появляются моментально. Уже хорошо. Значит сигнал доходит на сервер сразу, и проблема не в DNS. Уже конкретика.

Придётся копать strace, видимо.

[dmitri_kotov_PhD]

strace снял, добраться до причины не получилось.
Делал strace nginx, strace php-fpm.
Эти первые 17 секунд сервер грузит файлы php, судя по strace.

Проблему это не решило.
Как ещё проверять, пока не знаю. Вопрос актуален.

[ky0]

dmitri_kotov_PhD, поставить отдачу заглушку с веб-сервера - если поможет, значит дело в целом в РНР. Поставить РНР-заглушку вместо настоящего скрипта - если поможет, значит дело в коде. Включить slow-логи РНР.

[dmitri_kotov_PhD]

ky0, спасибо, пробовал. PHP тестовый скрипт отдаёт норм. Дело в коде, видимо. slow log пустые, почему-то. Остальные логи норм.

Answer 2

[Виктор Таран]

1. замерь скорость отдачи просо файла к примеру robots.txt в момент провисания, если зависает и он на17 секунд то это точно до php
2. - замерь скорость отдачи пхп файла с пхп инфо в нутри, ( исключишь проблемы работы fpm)
3 - напиши файли на пхп с запросом какой-то таблицы в бд с отображением скажем списка пользователей ( GPT) напишет тебе за 1 секунду
4. подключи ядро сайта и выведи хеллоу ворлд, и замеряй этот файл тоже ( не задействовать сложных компонентов)
Теперь у тебя есть целый инструментарий, на основание этого ты исключить ( проблему кеширования сайта когда он отдается быстро но дохнет при создание кеша)
2. Проблемы с sql поскольку провис будет при простом запросе к нему.
3. проблему с фпм
4. и соответственно просто текстовый файл отдается читсо nginx.
И только после этого будем обсуждать днс и nginx поскольку это самое мало вероятное.

Comments

[dmitri_kotov_PhD]

Спасибо большое.
Делал именно так. Сейчас понял, что забыл потестить без системы кэширования (WP-Rocket).
Всё остальное перепробовал прям по пунктам.

Спасибо большое, ещё раз покопаюсь и вернусь позже.

[Виктор Таран]

dmitri_kotov_PhD, добавь проверку крона и импорты экспорыт, генерации сайтмапов и тд в общем все тяжелые хиты которые могут длиться от 20 секунд, и нагружать I-O так что сайт висит в это время.

[dmitri_kotov_PhD]

Удалось поймать глюк на файлике robots.txt


Поймать глюк очень трудно: может проявиться уже через 20 минут, может через несколько часов, а может только на следующий день.

Также, удалось поймать этот же глюк с задержкой 17 секунд на "пустом" файле php, который выводит только текущее время (new DateTime) и простую строку а-ля HelloWorld.

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

Примечательно:
1. В системе свободно всего 3Гб оперативной памяти из 64Гб. Из них 50+Гб занимают кэши и прочее: кэш БД, +много пулов php-fpm, + много воркеров nginx. (сервер под постоянной нагрузкой со стороны ERP через Woocommerce REST API. Ошибок по этой части в логах нет.)

2. На системном разделе SSD свободно всего ~5-7Гб.

3. В логах не нашёл явной причины обсуждаемой проблемы. Перелопатил всё: системные логи ОС, логи nginx, php-fpm, mariadb и все остальные.

Также: как только словил данную проблему, повторно словить не получается. Сразу после этого всё "летает". Приходится по-новой подолгу ждать, когда проблема проявится.

На что только не думал: и на медленное создание новых воркеров nginx, и на стек TCP, но ведь ОЗУ свободной хоть сколько-то есть, всё выглядит достаточно цивильно. Не понимаю

+ещё: TCP slow start = 0. Отключен. Дело не в нём.

[dmitri_kotov_PhD]

Также, удалось поймать эту же задержку при загрузке просто png-картинки 150х150px из корня веб-директории.

[Виктор Таран]

dmitri_kotov_PhD,
Убедись что проблема локальная.
1. в хост файл впиши имя своего домена, дабы запрос шел сразу лькалььно.
2. вот тебе скрипт, там если че допииши

#!/bin/bash

# URL для опроса
URL="http://site.ru/robots.txt"
# Лог-файл
LOG_FILE="/path/to/your/logfile.log"

# Функция для проверки robots.txt
check_robots() {
    response=$(curl -o /dev/null -s -w "%{http_code} %{time_total}\n" "$URL")
    http_code=$(echo $response | awk '{print $1}')
    time_total=$(echo $response | awk '{print $2}')
    current_time=$(date '+%Y-%m-%d %H:%M:%S')  # Текущее время

    # Выводим результаты в одну строку
    echo "Время: $current_time | URL: $URL | Код ответа: $http_code | Время ответа: $time_total секунд"

    # Записываем результаты в лог-файл с меткой времени
    echo "$current_time - URL: $URL | Код ответа: $http_code | Время ответа: $time_total секунд" >> "$LOG_FILE"
}

# Бесконечный цикл
while true; do
    check_robots
    sleep 1  # Пауза в 1 секунду между запросами
done

соответственно запусти его с другой машины.
и смотри будет ли просадка локально, когда с другого компьютера проблема есть.

Поставь munin , там чтоб там был nginx

[dmitri_kotov_PhD]

Виктор Таран, ушёл пробовать, спасибо большое! За скрипт тоже, благодарю!

[Виктор Таран]

@dmitri_kotov каой результат ?

[dmitri_kotov_PhD]

Виктор Таран, накапливаю результаты, пока что ждём.
Прописал на этом же сервере в hosts имя домена, и с того же сервера запустил скрипт. Пока всё гладко.
(больше не от куда запускать, это единственная машина)

[dmitri_kotov_PhD]

Только что:
из браузера запрашиваю robots.txt: проблема ЕСТЬ (17 сек)
но локально запущенный на сервере скрипт не выдаёт задержек (в hosts 127.0.0.1 на URL сайта там прописан, обращение идёт на 127.0.0.1)

[dmitri_kotov_PhD]

C munin опыта не имел, - разбираюсь, что и как

[Виктор Таран]

ну как вариант проблема днс сервера особенно если это клаудфлеер, его же прикрывают по тихой. Перекинь ДНС на русский сервер там на яндесс днс или вк клауд.

[dmitri_kotov_PhD]

Протестировал с другого сервера из того же города (Дубай).
т.е. оба сервера находятся там в ОАЭ, совсем рядом.
DNS на CloudFlare.
Локальных кэширующих DNS нет.

Запускал данный скрипт с VPS, расположенной рядом с dedic продом, 2-мя способами:
1. Без модификаций hosts. (DNS запросы идут в интернет)
2. С модификацией hosts (явно прописал IP)

Оба сервера подключены к интернет через серый IPv4, подсеть датацентра. Без IPv6.

Результаты:
1. Продолжительность теста: ~1 час. Результат: 16 запросов словили ощутимую задержку до 5сек (см. скрин в прикреплении)


2. Продолжительность теста: ~2 часа. Результат: 12 просадок с временем ответа всего до 1 сек, за ДВА часа.


Получается, сам CloudFlare DNS даёт такую просадку? Получается, так.
В варианте 2 (с hosts), случаи, когда запрос занял ~1сек, рассматриваю как погрешность из-за прочего сетевого трафика. Это не 5 и не 17 секунд на запрос, всё-таки.

Получается, раскрутке и продвижению сайта среди юзеров того региона (ОАЭ) это может мешать, и они могут ловить эту задержку в 5 секунд,
а при доступе из РФ - все 17 секунд - и всё это в 0,44% случаев. Получается, так.
И всё из-за DNS..

А чтобы исключить проблему - только ставить свои DNS, и больше серверов с балансером на случай задержек в сети(?). Получается, вроде так.

[Виктор Таран]

Получается, сам CloudFlare DNS даёт такую просадку? Получается, так.

Да это же очередная жертва Роскомнадзора

[dmitri_kotov_PhD]

Виктор Таран, ок, понял, спасибо большое, наконец-то разобрались, значит, - ура!