LINUX.ORG.RU

Таймаут http

 , ,


0

1

client -> nginx (:443) -> app1 (:8080) -> POST http://remote/api/clients -> nginx2 -> app2

nginx, nginx2 - обычный nginx :-)
remote - либо 127.0.0.1 либо второй сервер удаленный
app1 - это node веб сервер на express
app2 - C++ приложение, в котором есть http сервер

В самом axios установлен timeout 5000. и он иногда срабатывает и клиенту отдается ошибка со стороны app1. Отчего срабатывает timeout не понятно. nginx2 в логах nginx регистрирует ответ от app2 с нормальным статусом (201), время запроса ~5 сек. и отдает app1 (но он уже отключился? по timeout). Ошибок нет от nginx. Если сокет отключился, куда передает nginx ответ? Или axios сокет не убивает, а только timeout генерирует? Пробовал дебажить, видно что timeout генерирует сам node socket, глубже не копал. И отчего может быть этот timeout? nginx2 получает ответ от app2 почти моментально, сверял логи, до секунды. Такое ощущение, что когда запрос на nginx2 приходит, он его в каком то буфере держит 5 сек., а потом отправляет на app2 и поэтому timeout. Что может быть?

Смотрел только

netstat -nlp4 | grep app2


на предмет Recv-Q - очередь на сокет не растет (я каждую сек. дрочил консоль, это нормально?), то есть app2 успевает все запросы обрабатывать. В самом nginx \ kernel ошибок нет (логов)

Сначала думал может запрос передается медленно, в nginx установил допом
client_body_timeout 3;
reset_timedout_connection on;
send_timeout 3;


Но тогда ngix отдавал бы с 408 статусом и axios от бы раньше отваливался, но постоянно ошибка timeout 5000.

Связка nginx2 -> app2.


map $http_authorization $api_dev_deny {
    default "1";
    "9342759823475947238979"  "0";
}
server {
    server_name exampla.com;
    access_log   /var/log/nginx/exampla.com.log main;
    error_log   /var/log/nginx/exampla.com.error.log;
    listen 80;
    listen 443 ssl; # managed by Certbot

    location ~ ^/api/(.*)$ {

        if ($api_dev_deny) {
            return 401;
        }
        proxy_pass http://127.0.0.1:1986/$2$is_args$args;
        proxy_http_version 1.1;
        proxy_set_header Host $host;
        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        proxy_http_version 1.1;
    }
}

★★★★

Отчего срабатывает timeout не понятно

Сервер где хостится? РФ или забугор? Забугор иногда ломает РКН, т.е. портят трафик (не важно http/https/udp или что там ещё, т.к. задача по устареванию оборудования у хостеров, чтоб сайты чебурнета переехали сюда).

peregrine ★★★★★
()
Последнее исправление: peregrine (всего исправлений: 1)

Такое ощущение, что когда запрос на nginx2 приходит, он его в каком то буфере держит 5 сек., а потом отправляет на app2 и поэтому timeout. Что может быть?

Это можно подтвердить записывая в логи app1 и app2 время, когда что отправлялось и когда приходило.

он его в каком то буфере держит 5 сек

Ага, я как-то раз неправильно настроил кеширование, у меня такое было)

goingUp ★★★★★
()

Например, у тебя в приложении лимит на число одновременных запросов

Дальше теория массвового обслуживания (цепи маркова). Скорость потока запросов превышает скорость обработки запросов. Запросы копятся в очереди, пока обработчик освободится

И, как уже советовали, добавь в access лог nginx все тайминги, связанные с upstream (connect, queue, response - все, что найдешь)

З.Ы. имел в виду «добавь в лог»

З.З.Ы. в целях совместимости, формат лога должен быть стандартным. Т.е. дополнительные поля добавляются после всех стандартных

router ★★★★★
()
Последнее исправление: router (всего исправлений: 2)
Ответ на: комментарий от goingUp

app1 19:30:05
app2 19:30:10
nginx 19:30:10 req from app1 5s ($request_time)
nginx req time = 19:30:10 - 5s = 19:30:05

Как пишет nginx $request_time это время когда от клиента получен первый байт и до времени когда клиенту передался последний байт.

А вот время когда был сделан (передан 1 байт) запрос к прокси - такого nginx не записыает.

Куда 5 сек. деются (или деваются)? В промежутке между app1 и app2
Могу предположить что реально из сервера app1 запрос ушел в 19:30:10, быстренько обработался nginx и вернулся обратно, но в axios уже таймаут сработал. Но если он сработал, то сокет должен быть закрытым и nginx выдал бы ошибку

gobot ★★★★
() автор топика
Ответ на: комментарий от router

Лог такой

log_format main '$host $scheme $remote_addr $realip_remote_addr - [$time_local] "$request" $status $body_bytes_sent $request_time "$http_referer" "$http_user_agent"';


Все что касается времени это $request_time и $time_local

gobot ★★★★
() автор топика