Upstream timed out
Vladimir Shiray
vlad at kbb1.com
Sun Sep 9 11:06:24 MSD 2007
Потому, что это был первый тест и на нем сразу же посыпались ошибки.
Внизу четыре новых теста, которые показывают, что проблема возникает
когда при запросе от nginx "backend" возвращает код возврата "304".
Особой разницы между удаленным и локальным тестом не наблюдается,
при обращении напрямую к "backend" данная проблема не проявляется.
Вот результат удаленного теста (rtt: 60ms) без "-H" для "-c 40"
siege -c 40 -t 60S http://dev.kbb1.com/icons/blank.gif
Transactions: 3984 hits
Availability: 100.00 %
Elapsed time: 60.48 secs
Data transferred: 0.56 MB
Response time: 0.13 secs
Transaction rate: 65.87 trans/sec
Throughput: 0.01 MB/sec
Concurrency: 8.57
Successful transactions: 3984
Failed transactions: 0
Longest transaction: 5.37
Shortest transaction: 0.12
И вот результат удаленного теста (rtt: 60ms) с "-H ... -c 5"
siege -c 5 -t 60S -H "If-Modified-Since: Sat, 20 Nov 2004 20:16:24 GMT"
http://dev.kbb1.com/icons/blank.gif
Transactions: 16 hits
Availability: 76.19 %
Elapsed time: 59.64 secs
Data transferred: 0.00 MB
Response time: 0.16 secs
Transaction rate: 0.27 trans/sec
Throughput: 0.00 MB/sec
Concurrency: 0.04
Successful transactions: 16
Failed transactions: 5
Longest transaction: 0.47
Shortest transaction: 0.12
Результат при обращении напрямую к Apache, минуя nginx, из соседнего
виртуального окружения.
siege -c 5 -t 60S -H "If-Modified-Since: Sat, 20 Nov 2004 20:16:24 GMT"
http://dev.kbb1.com/icons/blank.gif
Transactions: 586 hits
Availability: 100.00 %
Elapsed time: 60.20 secs
Data transferred: 0.00 MB
Response time: 0.00 secs
Transaction rate: 9.73 trans/sec
Throughput: 0.00 MB/sec
Concurrency: 0.01
Successful transactions: 586
Failed transactions: 0
Longest transaction: 0.01
Shortest transaction: 0.00
Результат при обращении через nginx, из соседнего
виртуального окружения.
siege -c 5 -t 60S -H "If-Modified-Since: Sat, 20 Nov 2004 20:16:24 GMT"
http://dev.kbb1.com/icons/blank.gif
Transactions: 14 hits
Availability: 73.68 %
Elapsed time: 60.42 secs
Data transferred: 0.00 MB
Response time: 0.00 secs
Transaction rate: 0.23 trans/sec
Throughput: 0.00 MB/sec
Concurrency: 0.00
Successful transactions: 14
Failed transactions: 5
Longest transaction: 0.01
Shortest transaction: 0.00
Alexey Karagodov wrote:
> на апач напрямую тоже самое ... а почему -c 5 ? отчего так мало?
>
> 2007/9/7, Vladimir Shiray <vlad at kbb1.com>:
>
>> С ним все по другому. Сразу же посыпались таймауты.
>> Хотя он и не дожидается таймаута nginx (120с), а срабатывает его
>> собственный (30с).
>>
>> siege -d 2 -c 5 -t 180S -H "If-Modified-Since: Sat, 20 Nov 2004 20:16:24
>> GMT" http://dev.kbb1.com/icons/blank.gif
>>
>> Lifting the server siege... done.
>> Transactions: 36 hits
>> Availability: 65.45 %
>> Elapsed time: 180.24 secs
>> Data transferred: 0.00 MB
>> Response time: 3.73 secs
>> Transaction rate: 0.20 trans/sec
>> Throughput: 0.00 MB/sec
>> Concurrency: 0.75
>> Successful transactions: 36
>> Failed transactions: 19
>> Longest transaction: 15.48
>> Shortest transaction: 0.44
>>
>> Если убрать параметр "-H" из теста, то все проходит без проблем.
>> При этом кол-во транзакций получается значительно больше.
>>
>> siege -d 2 -c 5 -t 180S http://dev.kbb1.com/icons/blank.gif
>>
>> Lifting the server siege... done.
>> Transactions: 588 hits
>> Availability: 100.00 %
>> Elapsed time: 180.51 secs
>> Data transferred: 0.08 MB
>> Response time: 0.50 secs
>> Transaction rate: 3.26 trans/sec
>> Throughput: 0.00 MB/sec
>> Concurrency: 1.64
>> Successful transactions: 588
>> Failed transactions: 0
>> Longest transaction: 3.59
>> Shortest transaction: 0.41
>>
>>
>> Alexey Karagodov wrote:
>>
>>> помучай его siege-ем например, нгинх, апач и т.д., чего получится
>>>
>>> 07.09.07, Vladimir Shiray<vlad at kbb1.com> написал(а):
>>>
>>>
>>>> Igor Sysoev wrote:
>>>>
>>>>
>>>>> On Fri, Sep 07, 2007 at 01:36:43PM +0300, Vladimir Shiray wrote:
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>> Igor Sysoev wrote:
>>>>>>
>>>>>>
>>>>>>
>>>>>>> On Thu, Sep 06, 2007 at 11:12:25AM +0300, Vladimir Shiray wrote:
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>> в error.log постоянно попадают ошибки, типа:
>>>>>>>> "upstream timed out (110: Connection timed out) while reading
>>>>>>>> upstream"
>>>>>>>>
>>>>>>>> После очистки лога и перезапуска nginx, на 150000 подключений
>>>>>>>> получил 426 таких сообщений.
>>>>>>>>
>>>>>>>> Сам сервер запущен внутри OpenVZ окружения (CentOS 4.5 32bit). Перед
>>>>>>>> последними
>>>>>>>> проверками, окружение было остановлено и запущено снова.
>>>>>>>> В /proc/user_beancounters и в логах ядра (2.6.18-ovz028stab039.1-smp)
>>>>>>>> все "чисто".
>>>>>>>>
>>>>>>>> У сервера есть три upstream, один докальный в "соседнем" VPS и два
>>>>>>>> удаленных
>>>>>>>> (rtt: 150ms и 60ms). Ошибки присутствуют для каждого из них.
>>>>>>>>
>>>>>>>> ------
>>>>>>>>
>>>>>>>> nginx-0.5.29 (c двумя патчами: patch-0.6.2.2, patch-0.6.5.1)
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>> Как уже посоветовали, можно логировать $upstream_response_time
>>>>>>>
>>>>>>> Эти ошибки на https'ных соединениях с бэкендами или на обычных ?
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>> Игорь, похоже ошибка появляется когда "backend" возвращает код "304".
>>>>>> Я проверил все последние локальные ошибки из error.log и в access.log
>>>>>> у всех из них стоит код 304.
>>>>>>
>>>>>> В моем предыдущем ответе на сообщение от "umask" есть также
>>>>>> соответствующие строки лога из Apache.
>>>>>>
>>>>>>
>>>>>>
>>>>> Вот этот запрос - /icons/blank.gif всегда заканичвается таймаутом или нет ?
>>>>>
>>>>>
>>>>>
>>>>>
>>>> Нет. Большая часть запрососв проходит нормально.
>>>>
>>>> Нагрузка на локальный backend очень небольшая,
>>>> поэтому сложно получить частоту появления таких ошибок.
>>>>
>>>> Пробовал пускать ab с удаленного сервера, но для такого простого теста
>>>> ошибка не проявляется. Внизу результаты. Тоже самое пускал и с
>>>> ключом "-k" - никакой существенной разницы.
>>>>
>>>> ab -n 100 -c 2 -H "If-Modified-Since: Sat, 20 Nov 2004 20:16:24 GMT"
>>>> http://dev.kbb1.com/icons/blank.gif
>>>>
>>>> Server Software: nginx/0.5.29
>>>> Server Hostname: dev.kbb1.com
>>>> Server Port: 80
>>>>
>>>> Document Path: /icons/blank.gi
>>>> Document Length: 1029 bytes
>>>>
>>>> Concurrency Level: 2
>>>> Time taken for tests: 22.600107 seconds
>>>> Complete requests: 100
>>>> Failed requests: 0
>>>> Write errors: 0
>>>> Non-2xx responses: 100
>>>> Total transferred: 130000 bytes
>>>> HTML transferred: 102900 bytes
>>>> Requests per second: 4.42 [#/sec] (mean)
>>>> Time per request: 452.002 [ms] (mean)
>>>> Time per request: 226.001 [ms] (mean, across all concurrent requests)
>>>> Transfer rate: 5.58 [Kbytes/sec] received
>>>>
>>>> Connection Times (ms)
>>>> min mean[+/-sd] median max
>>>> Connect: 196 224 11.0 226 240
>>>> Processing: 200 227 11.0 227 245
>>>> Waiting: 199 226 11.1 227 244
>>>> Total: 396 451 21.5 454 484
>>>>
>>>> Percentage of the requests served within a certain time (ms)
>>>> 50% 454
>>>> 66% 467
>>>> 75% 470
>>>> 80% 473
>>>> 90% 478
>>>> 95% 480
>>>> 98% 483
>>>> 99% 484
>>>> 100% 484 (longest request)
>>>>
>>>>
>>>>
>>
>>
More information about the nginx-ru
mailing list