ПРОЕКТЫ 


  АРХИВ 


Apache-Talk @lexa.ru 

Inet-Admins @info.east.ru 

Filmscanners @halftone.co.uk 

Security-alerts @yandex-team.ru 

nginx-ru @sysoev.ru 


  СТАТЬИ 


  ПЕРСОНАЛЬНОЕ 


  ПРОГРАММЫ 



ПИШИТЕ
ПИСЬМА












     АРХИВ :: nginx-ru
Nginx-ru mailing list archive (nginx-ru@sysoev.ru)

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: Upstream timed out




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

Внизу четыре новых теста, которые показывают, что проблема возникает
когда при запросе от 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@xxxxxxxx>:
С ним все по другому. Сразу же посыпались таймауты.
Хотя он и не дожидается таймаута 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@xxxxxxxx> написал(а):

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)







 




Copyright © Lexa Software, 1996-2009.